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

Server hangs or Assertion `0' fails in Protocol::end_statement on SELECT with UNION

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Critical
    • Resolution: Fixed
    • Affects Version/s: 10.2
    • Fix Version/s: 10.2.6
    • Component/s: Scripts & Clients, Server
    • Labels:
      None
    • Environment:
      Linux ws 3.16.0-4-amd64 #1 SMP Debian 3.16.39-1+deb8u2 (2017-03-07) x86_64 GNU/Linux ; Debian GNU/Linux 8.7 (jessie)

      Description

      Test case

      DROP TABLE IF EXISTS t1, t2;
      CREATE TABLE t1 (i INT) ENGINE=MyISAM;
      INSERT INTO t1 VALUES (1);
       
      CREATE TABLE t2 (pk INT PRIMARY KEY) ENGINE=MyISAM;
      INSERT INTO t2 VALUES (1),(2);
       
      # This is over-simplified query where GROUP BY and aggregate were removed as unnecessary
       
      SELECT 1
      UNION ALL
      SELECT i FROM (
        SELECT * FROM t1 WHERE i IN ( SELECT pk FROM t2 )
      ) AS sq HAVING i = 10
      ;
       
      # ... but the problem is also reproducible with proper GROUP BY
       
      SELECT 1, 2
      UNION ALL
      SELECT i, COUNT(*) FROM (
        SELECT * FROM t1 WHERE i IN ( SELECT pk FROM t2 )
      ) AS sq
      GROUP BY i
      HAVING i = 10
      ;
      

      On a debug server, either of the SELECTs above causes assertion failure:

      10.2 993323995648526781e5d22afbc77e260529a8b0

      mysqld: /data/src/10.2/sql/protocol.cc:587: void Protocol::end_statement(): Assertion `0' failed.
      170512 13:07:21 [ERROR] mysqld got signal 6 ;
       
      #7  0x00007fc6d05ee312 in __GI___assert_fail (assertion=0x7fc6d36e2fb8 "0", file=0x7fc6d36e2d58 "/data/src/10.2/sql/protocol.cc", line=587, function=0x7fc6d36e38a0 <Protocol::end_statement()::__PRETTY_FUNCTION__> "void Protocol::end_statement()") at assert.c:101
      #8  0x00007fc6d2bd1c1b in Protocol::end_statement (this=0x7fc6b8001098) at /data/src/10.2/sql/protocol.cc:587
      #9  0x00007fc6d2c974f4 in dispatch_command (command=COM_QUERY, thd=0x7fc6b8000b00, packet=0x7fc6b80087a1 "", packet_length=107, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:2362
      #10 0x00007fc6d2c943c8 in do_command (thd=0x7fc6b8000b00) at /data/src/10.2/sql/sql_parse.cc:1362
      #11 0x00007fc6d2ddf115 in do_handle_one_connection (connect=0x7fc6d5e86360) at /data/src/10.2/sql/sql_connect.cc:1354
      #12 0x00007fc6d2ddeea2 in handle_one_connection (arg=0x7fc6d5e86360) at /data/src/10.2/sql/sql_connect.cc:1260
      #13 0x00007fc6d31f8cac in pfs_spawn_thread (arg=0x7fc6d5e60c10) at /data/src/10.2/storage/perfschema/pfs.cc:1862
      #14 0x00007fc6d22b8064 in start_thread (arg=0x7fc6caab3700) at pthread_create.c:309
      #15 0x00007fc6d06a862d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
      

      On a non-debug server, the query seemingly hangs. It is reproducible both with MySQL client and mysqltest. With the client, for example, it looks like this:

      Connection where the query is executed -- never returns

      MariaDB [test]> SELECT 1
          -> UNION ALL
          -> SELECT i FROM (
          ->   SELECT * FROM t1 WHERE i IN ( SELECT pk FROM t2 )
          -> ) AS sq HAVING i = 10
          -> ;
      

      But in the processlist the query looks finished (thread 15)

      MariaDB [(none)]> show processlist;
      +----+-------------+-----------------+------+---------+------+-------------------------+------------------+----------+
      | Id | User        | Host            | db   | Command | Time | State                   | Info             | Progress |
      +----+-------------+-----------------+------+---------+------+-------------------------+------------------+----------+
      |  1 | system user |                 | NULL | Daemon  | NULL |                         | NULL             |    0.000 |
      |  2 | system user |                 | NULL | Daemon  | NULL |                         | NULL             |    0.000 |
      |  3 | system user |                 | NULL | Daemon  | NULL |                         | NULL             |    0.000 |
      |  4 | system user |                 | NULL | Daemon  | NULL |                         | NULL             |    0.000 |
      |  5 | system user |                 | NULL | Daemon  | NULL | InnoDB shutdown handler | NULL             |    0.000 |
      | 15 | root        | localhost:49808 | test | Sleep   |    6 |                         | NULL             |    0.000 |
      | 16 | root        | localhost:49809 | NULL | Query   |    0 | init                    | show processlist |    0.000 |
      +----+-------------+-----------------+------+---------+------+-------------------------+------------------+----------+
      7 rows in set (0.00 sec)
      

      Stack trace from the client (does not seem to change)

      Thread 1 (Thread 0x7ffbb3a12740 (LWP 27992)):
      #0  0x00007ffbb16c5ad0 in __poll_nocancel () at ../sysdeps/unix/syscall-template.S:81
      #1  0x00007ffbb3538e69 in poll (__timeout=-1, __nfds=1, __fds=0x7ffe360957e0) at /usr/include/x86_64-linux-gnu/bits/poll2.h:46
      #2  pvio_socket_wait_io_or_timeout (pvio=pvio@entry=0x7ffbb3c9de80, is_read=is_read@entry=1 '\001', timeout=timeout@entry=-1) at /data/src/10.2/libmariadb/plugins/pvio/pvio_socket.c:499
      #3  0x00007ffbb353926a in pvio_socket_read (pvio=0x7ffbb3c9de80, buffer=0x7ffbb3c9def0 "\001", length=16384) at /data/src/10.2/libmariadb/plugins/pvio/pvio_socket.c:300
      #4  0x00007ffbb3527d97 in ma_pvio_read (pvio=pvio@entry=0x7ffbb3c9de80, buffer=0x7ffbb3c9def0 "\001", length=length@entry=16384) at /data/src/10.2/libmariadb/libmariadb/ma_pvio.c:251
      #5  0x00007ffbb3527ec9 in ma_pvio_cache_read (pvio=0x7ffbb3c9de80, buffer=buffer@entry=0x7ffbb3ca22e0 "", length=length@entry=4) at /data/src/10.2/libmariadb/libmariadb/ma_pvio.c:293
      #6  0x00007ffbb353c5b7 in ma_real_read (net=0x7ffbb3ac9440 <mysql>, complen=complen@entry=0x7ffe36095920) at /data/src/10.2/libmariadb/libmariadb/ma_net.c:376
      #7  0x00007ffbb353cfed in ma_net_read (net=net@entry=0x7ffbb3ac9440 <mysql>) at /data/src/10.2/libmariadb/libmariadb/ma_net.c:430
      #8  0x00007ffbb352452c in ma_net_safe_read (mysql=mysql@entry=0x7ffbb3ac9440 <mysql>) at /data/src/10.2/libmariadb/libmariadb/mariadb_lib.c:188
      #9  0x00007ffbb3524c87 in mthd_my_read_rows (mysql=0x7ffbb3ac9440 <mysql>, mysql_fields=0x7ffbb3d381e8, fields=1) at /data/src/10.2/libmariadb/libmariadb/mariadb_lib.c:888
      #10 0x00007ffbb3521000 in mysql_store_result (mysql=0x7ffbb3ac9440 <mysql>) at /data/src/10.2/libmariadb/libmariadb/mariadb_lib.c:2189
      #11 0x00007ffbb3519190 in mysql_store_result_for_lazy (result=0x7ffe36095b28) at /data/src/10.2/client/mysql.cc:3002
      #12 0x00007ffbb351bfc0 in com_go (buffer=<optimized out>, line=<optimized out>) at /data/src/10.2/client/mysql.cc:3283
      #13 0x00007ffbb351d0bb in add_line (buffer=..., truncated=false, ml_comment=<synthetic pointer>, in_string=<synthetic pointer>, line_length=1, line=0x7ffbb3d8f6c0 ";") at /data/src/10.2/client/mysql.cc:2422
      #14 read_and_execute (interactive=<optimized out>) at /data/src/10.2/client/mysql.cc:2124
      #15 0x00007ffbb3515a39 in main (argc=4, argv=0x7ffbb3c9b4a0) at /data/src/10.2/client/mysql.cc:1291
      

      Stack trace from the server, does not seem to change either

      Thread 2 (Thread 0x7f903d7e5700 (LWP 27979)):
      #0  0x00007f903b928aed in poll () at ../sysdeps/unix/syscall-template.S:81
      #1  0x00007f903e5291ed in poll (__timeout=28800000, __nfds=1, __fds=0x7f903d7e47f0) at /usr/include/x86_64-linux-gnu/bits/poll2.h:46
      #2  vio_io_wait (vio=vio@entry=0x7f90408c0d38, event=event@entry=VIO_IO_EVENT_READ, timeout=28800000) at /data/src/10.2/vio/viosocket.c:945
      #3  0x00007f903e529278 in vio_socket_io_wait (vio=vio@entry=0x7f90408c0d38, event=event@entry=VIO_IO_EVENT_READ) at /data/src/10.2/vio/viosocket.c:108
      #4  0x00007f903e529371 in vio_read (vio=0x7f90408c0d38, buf=0x7f8fcc006be8 "\001", size=4) at /data/src/10.2/vio/viosocket.c:184
      #5  0x00007f903ddb806e in my_real_read (net=0x7f8fcc000be8, complen=complen@entry=0x7f903d7e49c8, header=<optimized out>) at /data/src/10.2/sql/net_serv.cc:888
      #6  0x00007f903ddb8dd9 in my_net_read_packet_reallen (net=0x7f8fcc000be8, read_from_server=<optimized out>, reallen=reallen@entry=0x7f903d7e4a18) at /data/src/10.2/sql/net_serv.cc:1158
      #7  0x00007f903ddb8f0b in my_net_read_packet (net=<optimized out>, read_from_server=<optimized out>) at /data/src/10.2/sql/net_serv.cc:1142
      #8  0x00007f903de46032 in do_command (thd=0x7f8fcc0009a8) at /data/src/10.2/sql/sql_parse.cc:1244
      #9  0x00007f903df09904 in do_handle_one_connection (connect=connect@entry=0x7f9040072b88) at /data/src/10.2/sql/sql_connect.cc:1354
      #10 0x00007f903df09aa4 in handle_one_connection (arg=0x7f9040072b88) at /data/src/10.2/sql/sql_connect.cc:1260
      #11 0x00007f903d541064 in start_thread (arg=0x7f903d7e5700) at pthread_create.c:309
      #12 0x00007f903b93162d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
       
      Thread 1 (Thread 0x7f903ebd4740 (LWP 27946)):
      #0  0x00007f903b928aed in poll () at ../sysdeps/unix/syscall-template.S:81
      #1  0x00007f903ddaf7b1 in poll (__timeout=-1, __nfds=2, __fds=0x7fff1264b450) at /usr/include/x86_64-linux-gnu/bits/poll2.h:41
      #2  handle_connections_sockets () at /data/src/10.2/sql/mysqld.cc:6568
      #3  0x00007f903ddb6eba in mysqld_main (argc=11, argv=0x7f9040029180) at /data/src/10.2/sql/mysqld.cc:6034
      #4  0x00007f903b86ab45 in __libc_start_main (main=0x7f903dd96a80 <main(int, char**)>, argc=11, argv=0x7fff1264bb78, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fff1264bb68) at libc-start.c:287
      #5  0x00007f903ddaad18 in _start ()
      

      Top doesn't show any significant activity either in client or in server.

      Neither assertion failure nor the hang are reproducible on 10.1 server, but reproducible if I connect to 10.2 server using 10.1 client.

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                igor Igor Babaev
                Reporter:
                elenst Elena Stepanova
              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: