Bug #82539 Socket_write: Assertion `n >= 0' failed
Submitted: 11 Aug 2016 8:00 Modified: 12 Dec 2016 10:28
Reporter: Umesh Shastry Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Group Replication Severity:S3 (Non-critical)
Version:5.7.14-labs-gr080-log OS:Oracle Linux (Red Hat Enterprise Linux Server release 7.1 (Maipo))
Assigned to: CPU Architecture:Any
Tags: crash

[11 Aug 2016 8:00] Umesh Shastry
Description:
While doing the bulk insert on a node, observed that most of the time it crashes. Please see How to repeat for rest details:

How to repeat:
-- Setup GR with 3 nodes - pls see setup steps/conf files etc in the attached file 82505.results of Bug #82505 

-- Connected node1

[umshastr@hod03]/export/umesh/server/source/bugs/mysql-5.7.14-labs: bin/mysql -uroot -S /tmp/mysql_ushastry14115.sock --prompt='node1>'
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 13
Server version: 5.7.14-labs-gr080-log Source distribution

Copyright (c) 2000, 2016, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

node1> SELECT * FROM performance_schema.replication_group_members;
+---------------------------+--------------------------------------+-------------+-------------+--------------+
| CHANNEL_NAME              | MEMBER_ID                            | MEMBER_HOST | MEMBER_PORT | MEMBER_STATE |
+---------------------------+--------------------------------------+-------------+-------------+--------------+
| group_replication_applier | 00a6d7dc-5f92-11e6-a704-0010e05f3e06 | hod03       |       14117 | ONLINE       |
| group_replication_applier | f993dd98-5f91-11e6-a2e5-0010e05f3e06 | hod03       |       14115 | ONLINE       |
| group_replication_applier | fad99f61-5f91-11e6-a50c-0010e05f3e06 | hod03       |       14116 | ONLINE       |
+---------------------------+--------------------------------------+-------------+-------------+--------------+
3 rows in set (0.00 sec)

node1>create database if not exists test;
Query OK, 1 row affected, 1 warning (0.00 sec)

node1>use test;
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
node1>drop table if exists t4;
Query OK, 0 rows affected, 1 warning (0.00 sec)

node1>CREATE TABLE `t4` (
    ->   `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
    ->   `balance` bigint(20),
    ->   `name2` varchar(250),
    ->   `name3` varchar(250),
    ->   `name4` varchar(250),
    ->   PRIMARY KEY (`id`)
    -> ) ENGINE=innodb;

Query OK, 0 rows affected (0.00 sec)

node1>
node1>set @id:=0;
Query OK, 0 rows affected (0.00 sec)

node1>
node1> insert into `t4` values
    ->   (@id:=@id+1,@id:=@id+1,md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000))
    -> ,  (@id:=@id+1,@id:=@id+1,md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000))
    -> , (@id:=@id+1,@id:=@id+1,md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000))
    -> , (@id:=@id+1,@id:=@id+1,md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000));
Query OK, 4 rows affected (0.00 sec)
Records: 4  Duplicates: 0  Warnings: 0

node1>
node1> insert into `t4`(`id`,`balance`,`name2`,`name3`,`name4`)
    ->    select  @id:=@id+1,@id:=@id+1,md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000)  from
    ->     `t4` k1, `t4` k2, `t4` k3, `t4` k4,`t4` k5,`t4` k6, `t4` k7, `t4` k8, `t4` k9,
    -> `t4` k0,`t4` ka, `t4` kb, `t4` kc, `t4` kd limit  23068672;
ERROR 2013 (HY000): Lost connection to MySQL server during query
node1>\q
Bye
[4]+  Aborted                 (core dumped) bin/mysqld --defaults-file=./node1.cnf
[umshastr@hod03]/export/umesh/server/source/bugs/mysql-5.7.14-labs:

Core was generated by `bin/mysqld --defaults-file=./node1.cnf'.
Program terminated with signal 6, Aborted.
#0  0x00007f924f2d9771 in pthread_kill () from /lib64/libpthread.so.0
Missing separate debuginfos, use: debuginfo-install glibc-2.17-78.0.1.el7.x86_64 libaio-0.3.109-12.el7.x86_64 libgcc-4.8.3-9.el7.x86_64 libstdc++-4.8.3-9.el7.x86_64 nss-softokn-freebl-3.16.2.3-13.el7_1.x86_64 numactl-libs-2.0.9-5.el7_1.x86_64
(gdb) bt
#0  0x00007f924f2d9771 in pthread_kill () from /lib64/libpthread.so.0
#1  0x00000000007a3db5 in handle_fatal_signal (sig=6) at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/sql/signal_handler.cc:220
#2  <signal handler called>
#3  0x00007f924dcd35d7 in raise () from /lib64/libc.so.6
#4  0x00007f924dcd4cc8 in abort () from /lib64/libc.so.6
#5  0x00007f924dccc546 in __assert_fail_base () from /lib64/libc.so.6
#6  0x00007f924dccc5f2 in __assert_fail () from /lib64/libc.so.6
#7  0x00007f92065dd3f7 in socket_write (n=-1285822848, _buf=0x7f8d15f2e010, wfd=0x7f91d8000ed0)
    at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/rapid/plugin/group_replication/libmysqlgcs/src/bindings/xcom/xcom/xcom_base.c:4325
#8  0x00007f920665007b in socket_write (n=-1285822848, _buf=0x7f8d15f2e010, wfd=0x7f91d8000ed0)
    at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/rapid/plugin/group_replication/libmysqlgcs/src/bindings/xcom/xcom/xcom_base.c:4341
#9  xcom_send_client_app_data (force=0, a=0x7f9228126930, fd=0x7f91d8000ed0)
    at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/rapid/plugin/group_replication/libmysqlgcs/src/bindings/xcom/xcom/xcom_base.c:4667
#10 xcom_client_send_data (size=<optimized out>, data=<optimized out>, fd=0x7f91d8000ed0)
    at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/rapid/plugin/group_replication/libmysqlgcs/src/bindings/xcom/xcom/xcom_base.c:4688
#11 0x00007f92066286b8 in Gcs_xcom_proxy_impl::xcom_client_send_data (this=0x7f91ec02e610, len=3009144251, data=0x7f8dc94ed010 "\001")
    at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/rapid/plugin/group_replication/libmysqlgcs/src/bindings/xcom/gcs_xcom_utils.cc:212
#12 0x00007f9206684aa8 in Gcs_xcom_communication::send_binding_message (this=0x7f91ec02d580, msg=..., msg_len=0x7f9228126eb0, cargo=<optimized out>)
    at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/rapid/plugin/group_replication/libmysqlgcs/src/bindings/xcom/gcs_xcom_communication_interface.cc:161
#13 0x00007f9206683bf8 in Gcs_xcom_communication::send_message (this=0x7f91ec02d580, message_to_send=...)
    at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/rapid/plugin/group_replication/libmysqlgcs/src/bindings/xcom/gcs_xcom_communication_interface.cc:94
#14 0x00007f92065f2e4a in send_transaction_message (msg=msg@entry=0x7f9228127300)
    at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/rapid/plugin/group_replication/src/observer_trans.cc:715
#15 0x00007f92065f3e64 in group_replication_trans_before_commit (param=0x7f9228127470)
    at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/rapid/plugin/group_replication/src/observer_trans.cc:505
#16 0x0000000000bfc2ef in Trans_delegate::before_commit (this=0x1e1c060 <delegates_init()::trans_mem>, thd=thd@entry=0x7f91ec0008c0, all=all@entry=false, trx_cache_log=<optimized out>,
    stmt_cache_log=stmt_cache_log@entry=0x7f91ec046ae8, cache_log_max_size=cache_log_max_size@entry=18446744073709547520)
    at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/sql/rpl_handler.cc:325
#17 0x0000000000e4dd7a in MYSQL_BIN_LOG::commit (this=0x1e3ea80 <mysql_bin_log>, thd=0x7f91ec0008c0, all=<optimized out>)
    at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/sql/binlog.cc:8167
#18 0x00000000007edc71 in ha_commit_trans (thd=thd@entry=0x7f91ec0008c0, all=all@entry=false, ignore_global_read_lock=ignore_global_read_lock@entry=false)
    at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/sql/handler.cc:1785
#19 0x0000000000d3104e in trans_commit_stmt (thd=thd@entry=0x7f91ec0008c0) at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/sql/transaction.cc:458
#20 0x0000000000c8e2aa in mysql_execute_command (thd=thd@entry=0x7f91ec0008c0, first_level=first_level@entry=true)
    at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/sql/sql_parse.cc:4991
#21 0x0000000000c910ed in mysql_parse (thd=thd@entry=0x7f91ec0008c0, parser_state=parser_state@entry=0x7f92281297a0)
    at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/sql/sql_parse.cc:5559
#22 0x0000000000c91a48 in dispatch_command (thd=thd@entry=0x7f91ec0008c0, com_data=com_data@entry=0x7f9228129e00, command=COM_QUERY)
    at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/sql/sql_parse.cc:1427
#23 0x0000000000c93367 in do_command (thd=thd@entry=0x7f91ec0008c0) at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/sql/sql_parse.cc:995
#24 0x0000000000d4c050 in handle_connection (arg=arg@entry=0x3214ce0) at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/sql/conn_handler/connection_handler_per_thread.cc:300
#25 0x0000000001217031 in pfs_spawn_thread (arg=0x328b360) at /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/storage/perfschema/pfs.cc:2188
#26 0x00007f924f2d4df5 in start_thread () from /lib64/libpthread.so.0
#27 0x00007f924dd9460d in clone () from /lib64/libc.so.6

-- extract from error log

mysqld: /export/umesh/server/source/bugs/mysql-5.7.14-labs-gr080/rapid/plugin/group_replication/libmysqlgcs/src/bindings/xcom/xcom/xcom_base.c:4325: socket_write: Assertion `n >= 0' failed.
07:45:20 UTC - mysqld got signal 6 ;
[11 Aug 2016 8:00] MySQL Verification Team
I observed this crash while preparing environment for Bug #82481
[12 Dec 2016 10:28] David Moss
Posted by developer:
 
Fixed in 5.7.17.