[MDEV-18694] Assertion `mysql_socket.fd != -1' failed in mysql_socket.h upon KILL_SERVER Created: 2019-02-22  Updated: 2019-08-16  Resolved: 2019-02-26

Status: Closed
Project: MariaDB Server
Component/s: Server
Affects Version/s: 10.2, 10.3, 10.4
Fix Version/s: 10.4.4

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Vladislav Vaintroub
Resolution: Fixed Votes: 0
Labels: None

Attachments: HTML File threads     HTML File threads_full    
Issue Links:
Relates
relates to MDEV-19200 innodb_fast_shutdown=0 triggers OOM k... Closed

 Description   

Happens regularly in concurrent tests upon server shutdown. As agreed, filing without a testcase.

10.3 4946eb7b

 
2019-02-22 10:25:19 0 [Warning] /home/vsts/server/bin/mysqld: Forcing close of thread 17  user: 'rqg'
 
2019-02-22 10:25:19 0 [Warning] /home/vsts/server/bin/mysqld: Forcing close of thread 16  user: 'rqg'
 
2019-02-22 10:25:19 0 [Warning] /home/vsts/server/bin/mysqld: Forcing close of thread 15  user: 'rqg'
 
mysqld: /home/vsts/src/include/mysql/psi/mysql_socket.h:738: inline_mysql_socket_send: Assertion `mysql_socket.fd != -1' failed.
 
190222 10:25:21 [ERROR] mysqld got signal 6 ;
 
 
 
#5  0x00007f87fc4cd02a in __GI_abort () at abort.c:89
 
#6  0x00007f87fc4c3bd7 in __assert_fail_base (fmt=<optimized out>, assertion=assertion@entry=0x555fef529460 "mysql_socket.fd != -1", file=file@entry=0x555fef529430 "/home/vsts/src/include/mysql/psi/mysql_socket.h", line=line@entry=738, function=function@entry=0x555fef529920 <__PRETTY_FUNCTION__.12480> "inline_mysql_socket_send") at assert.c:92
 
#7  0x00007f87fc4c3c82 in __GI___assert_fail (assertion=0x555fef529460 "mysql_socket.fd != -1", file=0x555fef529430 "/home/vsts/src/include/mysql/psi/mysql_socket.h", line=738, function=0x555fef529920 <__PRETTY_FUNCTION__.12480> "inline_mysql_socket_send") at assert.c:101
 
#8  0x0000555fef02da48 in inline_mysql_socket_send (src_file=0x555fef529478 "/home/vsts/src/vio/viosocket.c", src_line=298, mysql_socket=..., buf=0x7f87c800b300, n=74, flags=64) at /home/vsts/src/include/mysql/psi/mysql_socket.h:738
 
#9  0x0000555fef02e6ab in vio_write (vio=0x555ff2423b00, buf=0x7f87c800b300 "F", size=74) at /home/vsts/src/vio/viosocket.c:297
 
#10 0x0000555fee40a9d5 in net_real_write (net=0x7f87c8000ff8, packet=0x7f87c800b300 "F", len=74) at /home/vsts/src/sql/net_serv.cc:681
 
#11 0x0000555fee40a087 in net_flush (net=0x7f87c8000ff8) at /home/vsts/src/sql/net_serv.cc:383
 
#12 0x0000555fee40a4c2 in net_write_command (net=0x7f87c8000ff8, command=255 '\377', header=0x555fef06a740 "", head_len=0, packet=0x7f87f8ed81b0 "\261\a#70100Query execution was interrupted (max_statement_time exceeded)", len=69) at /home/vsts/src/sql/net_serv.cc:521
 
#13 0x0000555fee4117c2 in net_send_error_packet (thd=0x7f87c8000d10, sql_errno=1969, err=0x7f87c800629b "Query execution was interrupted (max_statement_time exceeded)", sqlstate=0x7f87c8006280 "70100") at /home/vsts/src/sql/protocol.cc:465
 
#14 0x0000555fee411e02 in Protocol::send_error (this=0x7f87c80012c8, sql_errno=1969, err_msg=0x7f87c800629b "Query execution was interrupted (max_statement_time exceeded)", sql_state=0x7f87c8006280 "70100") at /home/vsts/src/sql/protocol.cc:643
 
#15 0x0000555fee411ad5 in Protocol::end_statement (this=0x7f87c80012c8) at /home/vsts/src/sql/protocol.cc:569
 
#16 0x0000555fee51a382 in dispatch_command (command=COM_QUERY, thd=0x7f87c8000d10, packet=0x7f87c800b301 "", packet_length=89, is_com_multi=false, is_next_command=false) at /home/vsts/src/sql/sql_parse.cc:2411
 
#17 0x0000555fee517180 in do_command (thd=0x7f87c8000d10) at /home/vsts/src/sql/sql_parse.cc:1396
 
#18 0x0000555fee67f47b in do_handle_one_connection (connect=0x555ff18a5f80) at /home/vsts/src/sql/sql_connect.cc:1403
 
#19 0x0000555fee67f1cc in handle_one_connection (arg=0x555ff18a5f80) at /home/vsts/src/sql/sql_connect.cc:1309
 
#20 0x00007f87fd1086ba in start_thread (arg=0x7f87f8ed9700) at pthread_create.c:333
 
#21 0x00007f87fc59d41d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109


Query (0x7f87c8013ac8): LOAD DATA INFILE 'load_view_PP_J' REPLACE INTO TABLE view_PP_J /* QNO 1513 CON_ID 16 */
 
Connection ID (thread ID): 16
 
Status: KILL_SERVER

All threads' stack traces are attached.

It's known to happen on 10.3 and 10.4 at least. I have no information whether previous versions are affected.

 Comments   
Comment by Vladislav Vaintroub [ 2019-02-25 ]

3 last patches in bb-10.4-wlad

Comment by Sergey Vojtovich [ 2019-02-25 ]

Waiting for https://github.com/MariaDB/server/pull/1197 resolution.

Comment by Elena Stepanova [ 2019-03-04 ]

Got it (or a very similar one) on 10.2:

10.2 4ca2079

 
mysqld: /home/travis/src/include/mysql/psi/mysql_socket.h:738: inline_mysql_socket_send: Assertion `mysql_socket.fd != -1' failed.
 
190303 22:45:14 [ERROR] mysqld got signal 6 ;
 
 
 
sql/net_serv.cc:678(net_real_write)[0x55dd1286b936]
 
#7  0x00007f80d155fc82 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
 
#8  0x000055dd13380c9f in inline_mysql_socket_send (src_file=0x55dd137c59c8 "/home/travis/src/vio/viosocket.c", src_line=286, mysql_socket=..., buf=0x7f807c010760, n=40, flags=64) at /home/travis/src/include/mysql/psi/mysql_socket.h:738
 
#9  0x000055dd133818ed in vio_write (vio=0x55dd160d6950, buf=0x7f807c010760 "$", size=40) at /home/travis/src/vio/viosocket.c:285
 
#10 0x000055dd1286b936 in net_real_write (net=0x7f807c008e98, packet=0x7f807c010760 "$", len=40) at /home/travis/src/sql/net_serv.cc:678
 
#11 0x000055dd1286aff9 in net_flush (net=0x7f807c008e98) at /home/travis/src/sql/net_serv.cc:380
 
#12 0x000055dd1286b434 in net_write_command (net=0x7f807c008e98, command=255 '\377', header=0x55dd133bcf80 "", head_len=0, packet=0x7f80d0467db0 "\035\004#08S01Server shutdown in progress", len=35) at /home/travis/src/sql/net_serv.cc:518
 
#13 0x000055dd128722ba in net_send_error_packet (thd=0x7f807c008bb0, sql_errno=1053, err=0x7f807c00dd63 "Server shutdown in progress", sqlstate=0x7f807c00df68 "08S01") at /home/travis/src/sql/protocol.cc:465
 
#14 0x000055dd12872850 in Protocol::send_error (this=0x7f807c009168, sql_errno=1053, err_msg=0x7f807c00dd63 "Server shutdown in progress", sql_state=0x7f807c00df68 "08S01") at /home/travis/src/sql/protocol.cc:642
 
#15 0x000055dd1287252b in Protocol::end_statement (this=0x7f807c009168) at /home/travis/src/sql/protocol.cc:568
 
#16 0x000055dd1293a28c in dispatch_command (command=COM_QUERY, thd=0x7f807c008bb0, packet=0x7f807c010761 "", packet_length=62, is_com_multi=false, is_next_command=false) at /home/travis/src/sql/sql_parse.cc:2387
 
#17 0x000055dd1293705c in do_command (thd=0x7f807c008bb0) at /home/travis/src/sql/sql_parse.cc:1379
 
#18 0x000055dd12a8a0c9 in do_handle_one_connection (connect=0x55dd1602b890) at /home/travis/src/sql/sql_connect.cc:1336
 
#19 0x000055dd12a89e49 in handle_one_connection (arg=0x55dd1602b890) at /home/travis/src/sql/sql_connect.cc:1242
 
#20 0x00007f80d21a46ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
 
#21 0x00007f80d163941d in clone () from /lib/x86_64-linux-gnu/libc.so.6
 
 
 
Query (0x7f807c018fd8): INSERT INTO `t2` SELECT * FROM `t3` /* QNO 15124 CON_ID 17 */
 
Connection ID (thread ID): 17
 
Status: KILL_SERVER

Generated at Thu Feb 08 08:46:02 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.