mysqlexec/db server: Lost connection to MySQL server during query

[dylan2intel]

^MVuser 33:Orders Done
^MVuser 33:End:Tue Jan 18 02:31:37 UTC 2022
^MVuser 33:FINISHED SUCCESS
^MIs it complete ?: false
Vuser 1:Workers: 0 Active 128 Done
^MVuser 1:CREATING TPCC STORED PROCEDURES
^MError in Virtual User 1: mysqlexec/db server: Lost connection to MySQL server during query
^MVuser 1:FINISHED FAILED
^MALL VIRTUAL USERS COMPLETE
^MIs it complete ?: true
BUILD SCHEMA COMPLETE

HammerDB4.2

[root@benchmark-pv6dd configmap]# cat build_hammer.tcl
#!/bin/tclsh
puts "SETTING CONFIGURATION"
global complete
proc wait_to_complete {} {
global complete
set complete [vucomplete]
puts "Is it complete ?: $complete"
if {!$complete} {
after 5000 wait_to_complete
} else {
puts "BUILD SCHEMA COMPLETE"
exit
}
}
dbset db mysql
diset connection mysql_host db-service
diset connection mysql_port 3306
diset tpcc mysql_user root
diset tpcc mysql_pass Mysql@123
diset tpcc mysql_count_ware 800
diset tpcc mysql_partition true
diset tpcc mysql_num_vu 128
diset tpcc mysql_storage_engine innodb

print dict
buildschema
wait_to_complete
vwait forever
[root@benchmark-pv6dd configmap]# nproc
128

[sm-shaw]

The error here is:

mysqlexec/db server: Lost connection to MySQL server during query

So the monitor virtual user will connect, create the user and tables (load the item table) and then wait for the other virtual users to finish. Once complete, it will then create the stored procedures. It looks like your monitor virtual user was disconnected whilst waiting.

Check timeout values to ensure that the monitor virtual user will not be forcibly disconnected. Also verify that the load time is in expected values e.g. see #295

Here for TPROC-C 800WH with 64VUs mariadb took 20 min 46 secs to load with the original loading script. If it is taking a lot longer verify your configuration and try reducing the number of virtual users from 128.

[sm-shaw]

As advised previously, It still looks like your monitor virtual user was disconnected whilst waiting.

How long does the build take? You, advise your connect timeout is 180 seconds which is 3 minutes
connect_timeout = {{ .MYSQL_CONNECT_TIMEOUT }} # increase default value 10 seconds to 180

If the build virtual users do not load the schema within 3 minutes then the monitor virtual user will be disconnected.
the MySQL default is 28800/8 hours - try setting the timeouts to the defaults.

A useful tip if troubleshooting schema build configuration errors - try building something small first eg 10 warehouses with 10 virtual users that takes a minute or so. Make sure everything builds correctly, drop the smaller schema and then create the larger one. Thi can save you a lot of time in the long run.

[dylan2intel]

'If the build virtual users do not load the schema within 3 minutes then the monitor virtual user will be disconnected.
the MySQL default is 28800/8 hours - try setting the timeouts to the defaults.'
NOT AGREE WITH YOU AS ABOVE.

Here is mysql reference: connect_timeout

'The number of seconds that the mysqld server waits for a connect packet before responding with Bad handshake. The default value is 10 seconds.'

Increasing the connect_timeout value might help if clients frequently encounter errors of the form Lost connection to MySQL server at 'XXX', system error: errno.

Set to 3mins is really enough, cannot imagine that a connection without handshake in 180 seconds.

Looking into the source code that associated where failed on step to create tpcc procedure, btw. always failed on this step.

mysqloltp.tcl
...
for { set i 1 } { $i <= 5 } { incr i } { mysqlexec $mysql_handler $sql($i) }

Totally 5 SQLs expected to execute.

My question is that if to create new db connection for each sql or shared only one connection for 5 SQLs ?

[dylan2intel]

Btw, I cannot reduce the warehouse number, because I am running apples-to-apples benchmarking with corresponding one.
Upgrade version from 4.2 to 4.3, the issue reproduced. I am not sure if it is related to mysql deployed on kubernetes.

[sm-shaw]

Yes it should have been wait_timeout rather than connect_timeout. The connect_timeout is the time to establish a connection, the wait_timeout is the time to keep that connection alive when there is no activity. The monitor virtual user will login create the tables and wait for them to be loaded, if this time is longer than the wait_timeout MySQL will terminate the connection.
Yes it errors on that step because the session is no longer connected.
Look in the server logs for details of the connection being terminated.

[dylan2intel]

Thank you for your quickly reply.

Double-checked the wait_timeout is 28800/8 hours by default without change. Basically 800 warehouse will run 2-3h, so the default value is OK.

I am not sure if it is related to the setup, since deployed 2 kubernetes pods. one running with hammerdb, the other with db.
The networking between the 2 pods maybe is an impact factor.

Enabling db error log, hope to address the root cause... will update you if any new findings.

[dylan2intel]

Here is new findings

ubuntu@node1:$ kubectl get pods -A
NAMESPACE NAME READY STATUS RESTARTS AGE
kube-system coredns-8474476ff8-h97w7 1/1 Running 0 45m
kube-system dns-autoscaler-747ff97c96-pmt62 1/1 Running 0 45m
kube-system kube-apiserver-node1 1/1 Running 0 46m
kube-system kube-controller-manager-node1 1/1 Running 1 46m
kube-system kube-proxy-dl6qs 1/1 Running 0 45m
kube-system kube-scheduler-node1 1/1 Running 1 46m
kube-system nodelocaldns-rvg8b 1/1 Running 0 45m
kube-system weave-net-9zgz8 2/2 Running 1 45m
node-feature-discovery nfd-master-75b7c4d897-zllsl 1/1 Running 0 44m
node-feature-discovery nfd-worker-thxm5 1/1 Running 0 44m
test-aws-hammerdb-tpcc-mysql-disk-hugepage-off-031818 benchmark-z49ws 1/1 Running 0 37m
test-aws-hammerdb-tpcc-mysql-disk-hugepage-off-031818 mysql-c8b8964-bjz6p 1/1 Running 0 37m
ubuntu@node1:$ kubectl exec -it -n test-aws-hammerdb-tpcc-mysql-disk-hugepage-off-031818 mysql-c8b8964-bjz6p bash
kubectl exec [POD] [COMMAND] is DEPRECATED and will be removed in a future version. Use kubectl exec [POD] -- [COMMAND] instead.
root@mysql-c8b8964-bjz6p:/# tail -f /var/log/mysql/error.log
2022-03-18T10:46:25.903228Z 52 [Note] [MY-010914] [Server] Aborted connection 52 to db: 'tpcc' user: 'root' host: '10.233.64.6' (Got an error reading communication packets).
2022-03-18T10:46:25.903229Z 45 [Note] [MY-010914] [Server] Aborted connection 45 to db: 'tpcc' user: 'root' host: '10.233.64.6' (Got an error reading communication packets).
2022-03-18T10:46:25.903230Z 49 [Note] [MY-010914] [Server] Aborted connection 49 to db: 'tpcc' user: 'root' host: '10.233.64.6' (Got an error reading communication packets).
2022-03-18T10:46:25.903231Z 44 [Note] [MY-010914] [Server] Aborted connection 44 to db: 'tpcc' user: 'root' host: '10.233.64.6' (Got an error reading communication packets).
2022-03-18T10:46:25.903233Z 48 [Note] [MY-010914] [Server] Aborted connection 48 to db: 'tpcc' user: 'root' host: '10.233.64.6' (Got an error reading communication packets).
2022-03-18T10:46:25.903233Z 47 [Note] [MY-010914] [Server] Aborted connection 47 to db: 'tpcc' user: 'root' host: '10.233.64.6' (Got an error reading communication packets).
2022-03-18T10:46:25.903235Z 58 [Note] [MY-010914] [Server] Aborted connection 58 to db: 'tpcc' user: 'root' host: '10.233.64.6' (Got an error reading communication packets).
2022-03-18T10:46:25.903235Z 59 [Note] [MY-010914] [Server] Aborted connection 59 to db: 'tpcc' user: 'root' host: '10.233.64.6' (Got an error reading communication packets).
2022-03-18T10:46:25.902422Z 101 [Note] [MY-010914] [Server] Aborted connection 101 to db: 'tpcc' user: 'root' host: '10.233.64.6' (Got an error reading communication packets).
2022-03-18T10:46:25.902811Z 82 [Note] [MY-010914] [Server] Aborted connection 82 to db: 'tpcc' user: 'root' host: '10.233.64.6' (Got an error reading communication packets).

[dylan2intel]

Why 'Got an error reading communication packets' ???

[dylan2intel]

Attach configuration
root@mysql-c8b8964-bjz6p:/# cat /etc/mysql/conf.d/mysqld.cnf

Copyright (c) 2014, 2017, Oracle and/or its affiliates. All rights reserved.

This program is free software; you can redistribute it and/or modify

it under the terms of the GNU General Public License, version 2.0,

as published by the Free Software Foundation.

This program is also distributed with certain software (including

but not limited to OpenSSL) that is licensed under separate terms,

as designated in a particular file or component or in included license

documentation. The authors of MySQL hereby grant you an additional

permission to link the program and your derivative works with the

separately licensed software that they have included with MySQL.

This program is distributed in the hope that it will be useful,

but WITHOUT ANY WARRANTY; without even the implied warranty of

MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the

GNU General Public License, version 2.0, for more details.

You should have received a copy of the GNU General Public License

along with this program; if not, write to the Free Software

Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA

The MySQL Server configuration file.

For explanations see

http://dev.mysql.com/doc/mysql/en/server-system-variables.html

[mysqld]
default_authentication_plugin=mysql_native_password #mysql_native_password

general

#port=3306
max_connections=4000 #4000
table_open_cache=8000 #8000
table_open_cache_instances=16 #16
back_log=1500 #1500
default_password_lifetime=0 #0
ssl=0 #0
performance_schema=OFF #OFF
max_prepared_stmt_count=128000 #128000
skip_log_bin=1 #1
character_set_server=latin1 #latin1
collation_server=latin1_swedish_ci #latin1_swedish_ci
transaction_isolation=REPEATABLE-READ #REPEATABLE-READ

files

innodb_log_file_size=1024M #1024M
innodb_log_files_in_group=32 #32
innodb_open_files=4000 #4000

buffers

innodb_buffer_pool_size=64000M #64000M
innodb_buffer_pool_instances=16 #16
innodb_log_buffer_size=64M #64M

tune

innodb_doublewrite=0 #0
innodb_thread_concurrency=0 #0
innodb_flush_log_at_trx_commit=0 #0
innodb_max_dirty_pages_pct=90 #90
innodb_max_dirty_pages_pct_lwm=10 #10
join_buffer_size=32K #32K
sort_buffer_size=32K #32K
innodb_use_native_aio=1 #1
innodb_stats_persistent=1 #1
innodb_spin_wait_delay=6 #6
innodb_max_purge_lag_delay=300000 #300000
innodb_max_purge_lag=0 #0
#innodb_flush_method=O_DIRECT_NO_FSYNC
innodb_checksum_algorithm=none #none
innodb_io_capacity=4000 #4000
innodb_io_capacity_max=20000 #20000
innodb_lru_scan_depth=9000 #9000
innodb_change_buffering=none #none
innodb_read_only=0 #0
innodb_page_cleaners=4 #4
innodb_undo_log_truncate=off #off

perf special

innodb_adaptive_flushing=1 #1
innodb_flush_neighbors=0 #0
innodb_read_io_threads=16 #16
innodb_write_io_threads=16 #16
innodb_purge_threads=4 #4
innodb_adaptive_hash_index=0 #0
#bind-address=10.0.0.5
innodb_flush_method=O_DIRECT_NO_FSYNC

FIX cloud issue 'Error in Virtual User 1: mysqlexec/db server: Lost connection to MySQL server during query'

connect_timeout=86400
max_connect_errors=10000
net_read_timeout=86400
net_write_timeout=86400
max_allowed_packet=1G

log-error=/var/log/mysql/error.log
log_error_verbosity=3 # by default the value is 2, (1, ERROR) (2, [ERROR, WARNING]) (3, [ERROR, WARNING, INFORMATION])

[dylan2intel]

Actually the parameters DOESN'T work
connect_timeout=86400
max_connect_errors=10000
net_read_timeout=86400
net_write_timeout=86400
max_allowed_packet=1G

[dylan2intel]

Actually from my point of view on the logic:

Why not create store procedure before loading the table data?

mysqloltp.tcl
...
if { $threaded eq "SINGLE-THREADED" || $threaded eq "MULTI-THREADED" && $myposition eq 1 } {
CreateStoredProcs $mysql_handler ##### is it possible here connection closed due to hold too much time waiting for all data loading thread finished
GatherStatistics $mysql_handler
puts "[ string toupper $db ] SCHEMA COMPLETE"
mysqlclose $mysql_handler
return
}
...

[lanseguhun]

hello,did you have resolve the problem?

[sm-shaw]

Got an error reading communication packets is from your TCP/IP configuration and out of scope for HammerDB support.
HammerDB creates and loads the tables first because multiple databases are supported and errors may result when stored procedures are created that reference objects that do not already exist.
Having said that, HammerDB is fully scripted so that the user can change the configuration, whenever and however they wish so if you want to, you can use the datagen option to manually create the schema and load the data from flat files https://www.hammerdb.com/docs/ch13s03.html. This option was intentionally created for use from the cloud.

[sm-shaw]

You should also set interactive_timeout as shown, HammerDB is using mysql_real_connect and passing the interactive option.

[dylan2intel]

By default, the interactive_timeout is 28800(8h), but actually the connection broken in 1h.

[sm-shaw]

So there is likely to be a timeout value set elsewhere to 1hr. You can see if it is MariaDB/MySQL by checking for "Got timeout reading communication packets" in the log.

[lanseguhun]

i get some bug information form https://bugs.mysql.com/bug.php?id=105229,so i run a test and reference the code mysql_autoreconnect_test.cc in the bug(105229),and disable autoconnect line; i get the same error "[2006] MySQL server has gone away",then i set global wait_timeout=28800 ,this's be ok again. so may hammerdb increace auto-reconnect option? use that option is aways be ok in my test.

#include <mysql/mysql.h>
#include <stdlib.h>
#include <stdio.h>
#include <string.h>
#include <unistd.h>

#define DB_SERVER "127.0.0.1"
#define DB_USERNAME "root"
#define DB_PASSWORD "P@ssw0rd"
#define DB_DATABASE "information_schema"

void finish_with_error(MYSQL *con)
{
fprintf(stderr, "[%i] %s\n", mysql_errno(con), mysql_error(con));
mysql_close(con);
exit(1);
}

bool send_query(MYSQL mysql_con, const char query)
{
printf("Sending query: %s\n", query);

int res = mysql_query(mysql_con, query);
if (res != 0) {
    fprintf(stderr, "mysql_query error: %i\n", res);
    return false;
}

MYSQL_RES *result = mysql_store_result(mysql_con);
if (result == NULL) {
    printf("No result-set\n");
}
else {
   MYSQL_ROW row = mysql_fetch_row(result);
   printf("Result: %s\n", row[0]);
      mysql_free_result(result);
}

printf("\n");
return true;

}

int main(int argc, char** argv)
{
MYSQL *mysql_con = NULL;
bool reconnect = 1;

/* init connection object */
mysql_con = mysql_init(NULL);
if (!mysql_con) {
    fprintf(stderr, "%s\n", "debug: could not initialize database");
    exit(1);
}

/* enable auto-reconnect
if (mysql_options(mysql_con, MYSQL_OPT_RECONNECT, &reconnect)) {
    fprintf(stderr, "mysql_options failed.");
} */

/* connect to server */
if (mysql_real_connect(mysql_con,
                        DB_SERVER,
                        DB_USERNAME,
                        DB_PASSWORD,
                        DB_DATABASE,
                        0,
                        NULL,
                        CLIENT_MULTI_RESULTS) == NULL) {
    fprintf(stderr, "Failed to connect.\n");
    finish_with_error(mysql_con);
}

/* send query #1 */
if (!send_query(mysql_con, "SELECT 1")) {
    finish_with_error(mysql_con);
}

/* wait until connection times-out */
printf("Waiting for 420s\n");
sleep(420);

/* send query #2 */
if (!send_query(mysql_con, "SELECT 2")) {
    finish_with_error(mysql_con);
}

printf("Test successfully completed\n");

mysql_close(mysql_con);
return 0;

}

[sm-shaw]

This is something we can look at in the underlying libraries for both MySQL and MariaDB in a forthcoming release. For now set global wait_timeout=28800 is a good workaround to prevent disconnects from this MySQL bug.

[lanseguhun]

yes，we can set wait_timeout=28800 in my.cnf，then hammerdb will be run without the problem.