Bug #97805 Async client read-after-free/write-after-free issues from valgrind
Submitted: 27 Nov 2019 1:43 Modified: 27 Nov 2019 5:56
Reporter: Herman Lee Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: C API (client library) Severity:S7 (Test Cases)
Version:8.0.17, 8.0.18 OS:Any
Assigned to: CPU Architecture:Any

[27 Nov 2019 1:43] Herman Lee
Description:
Valgrind is reporting problems with read-after-free on tests.

CURRENT_TEST: main.flush_read_lock_kill
==297162== Memcheck, a memory error detector
==297162== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al.
==297162== Using Valgrind-3.15.0 and LibVEX; rerun with -h for copyright info
==297162== Command: /mnt/btrfs/trunk-git-mysql80-int-77127098-1574406259/_build-8.0-Valgrind/runtime_output_directory//mysqltest --defaults-file=/mnt/btrfs/trunk-git-mysql80-int-77127098-1574406259/_build-8.0-Valgrind/mysql-test/var/6/my.cnf --silent --tmpdir=/tmp/xLZSDUAkV3/6 --character-sets-dir=/mnt/btrfs/trunk-git-mysql80-int-77127098-1574406259/share/charsets --logdir=/mnt/btrfs/trunk-git-mysql80-int-77127098-1574406259/_build-8.0-Valgrind/mysql-test/var/6/log --database=test --plugin_dir=/mnt/btrfs/trunk-git-mysql80-int-77127098-1574406259/_build-8.0-Valgrind/plugin_output_directory --timer-file=/mnt/btrfs/trunk-git-mysql80-int-77127098-1574406259/_build-8.0-Valgrind/mysql-test/var/6/log/timer --async-client --test-file=/mnt/btrfs/trunk-git-mysql80-int-77127098-1574406259/mysql-test/t/flush_read_lock_kill.test --tail-lines=20 --result-file=/mnt/btrfs/trunk-git-mysql80-int-77127098-1574406259/mysql-test/r/flush_read_lock_kill.result
==297162== 
==297162== Invalid write of size 1
==297162==    at 0x799706: cli_safe_read_with_ok_nonblocking(MYSQL*, bool, bool*, unsigned long*) (client.cc:1098)
==297162==    by 0x799EB8: cli_safe_read_nonblocking (client.cc:1109)
==297162==    by 0x7ADFC9: cli_read_query_result_nonblocking(MYSQL*) (client.cc:7079)
==297162==    by 0x734185: async_mysql_read_query_result_wrapper(MYSQL*) (mysqltest.cc:955)
==297162==    by 0x733CC1: mysql_read_query_result_wrapper(MYSQL*) (mysqltest.cc:1076)
==297162==    by 0x7322C4: run_query_normal(st_connection*, st_command*, int, char const*, unsigned long, DYNAMIC_STRING*, DYNAMIC_STRING*) (mysqltest.cc:8582)
==297162==    by 0x7230C2: run_query(st_connection*, st_command*, int) (mysqltest.cc:9073)
==297162==    by 0x71B30A: main (mysqltest.cc:9984)
==297162==  Address 0x77d7ea0 is 224 bytes inside a block of size 232 free'd
==297162==    at 0x4C2FFDB: free (vg_replace_malloc.c:540)
==297162==    by 0x860554: my_raw_free(void*) (my_malloc.cc:281)
==297162==    by 0x86048E: my_free(void*) (my_malloc.cc:153)
==297162==    by 0x7BA3EE: net_extension_free(NET*) (net_serv.cc:114)
==297162==    by 0x79B5E7: end_server (client.cc:1811)
==297162==    by 0x79981D: cli_safe_read_with_ok_complete(MYSQL*, bool, bool*, unsigned long) (client.cc:1158)
==297162==    by 0x7996FA: cli_safe_read_with_ok_nonblocking(MYSQL*, bool, bool*, unsigned long*) (client.cc:1094)
==297162==    by 0x799EB8: cli_safe_read_nonblocking (client.cc:1109)
==297162==    by 0x7ADFC9: cli_read_query_result_nonblocking(MYSQL*) (client.cc:7079)
==297162==    by 0x734185: async_mysql_read_query_result_wrapper(MYSQL*) (mysqltest.cc:955)
==297162==    by 0x733CC1: mysql_read_query_result_wrapper(MYSQL*) (mysqltest.cc:1076)
==297162==    by 0x7322C4: run_query_normal(st_connection*, st_command*, int, char const*, unsigned long, DYNAMIC_STRING*, DYNAMIC_STRING*) (mysqltest.cc:8582)
==297162==    by 0x7230C2: run_query(st_connection*, st_command*, int) (mysqltest.cc:9073)
==297162==    by 0x71B30A: main (mysqltest.cc:9984)
==297162==  Block was alloc'd at
==297162==    at 0x4C31195: calloc (vg_replace_malloc.c:762)
==297162==    by 0x86003E: my_raw_malloc(unsigned long, int) (my_malloc.cc:197)
==297162==    by 0x85FF69: my_malloc(unsigned int, unsigned long, int) (my_malloc.cc:81)
==297162==    by 0x7BA36D: net_extension_init() (net_serv.cc:103)
==297162==    by 0x7BA586: my_net_init(NET*, Vio*) (net_serv.cc:150)
==297162==    by 0x7ACB59: csm_complete_connect(mysql_async_connect*) (client.cc:6206)
==297162==    by 0x7A5168: mysql_real_connect_nonblocking (client.cc:5764)
==297162==    by 0x72D449: async_mysql_real_connect_wrapper(MYSQL*, char const*, char const*, char const*, char const*, unsigned int, char const*, unsigned long) (mysqltest.cc:994)
==297162==    by 0x72D32A: mysql_real_connect_wrapper(MYSQL*, char const*, char const*, char const*, char const*, unsigned int, char const*, unsigned long) (mysqltest.cc:1102)
==297162==    by 0x72EA50: connect_n_handle_errors(st_command*, MYSQL*, char const*, char const*, char const*, char const*, int, char const*) (mysqltest.cc:6571)
==297162==    by 0x71DDB9: do_connect(st_command*) (mysqltest.cc:6876)
==297162==    by 0x71AC81: main (mysqltest.cc:9752)

The code is caching the NET_ASYNC pointer from the net structure on the stack using the net_async variable. However, this pointer can be freed in calls to cli_safe_read_with_ok_complete(), which can possibly call end_server() to perform the free. The caller function then access the net_async variable from the stack, which has been freed.

The functions where the pointer is cached are cli_read_metadata_ex_nonblocking, cli_read_rows_nonblocking, cli_safe_read_with_ok_nonblocking, and cli_read_query_result_nonblocking. There are potentially others too.

How to repeat:
Build with valgrind.

mtr --valgrind --mem --async-client main.flush_read_lock_kill

Suggested fix:
After calls to cli_safe_read_*, refresh the net_async pointer, which could be null.
[27 Nov 2019 5:56] Umesh Shastry
Hello Herman Lee,

Thank you for the report and feedback.
Verified as described with 8.0.18 valgrind build.

regards,
Umesh
[27 Nov 2019 5:59] Umesh Shastry
Test results - 8.0.18

Attachment: 97805_8.0.18.results (application/octet-stream, text), 11.71 KiB.