Percona Server moved to https://jira.percona.com/projects/PS

Valgrind: memory leak in scalability_metrics

Bug #1334570 reported by Laurynas Biveinis on 2014-06-26

This bug affects 1 person

	Status	Importance	Assigned to	Milestone
Percona Server moved to https://jira.percona.com/projects/PS	Fix Released	Medium	Sergei Glushchenko	Percona Server moved to https://jira.percona.com/projects/PS 5.6.21-69.0
5.1	Invalid	Undecided	Unassigned
5.5	Fix Released	Medium	Sergei Glushchenko	Percona Server moved to https://jira.percona.com/projects/PS 5.5.40-36.1
5.6	Fix Released	Medium	Sergei Glushchenko	Percona Server moved to https://jira.percona.com/projects/PS 5.6.21-69.0

Bug Description

./mysql-test-run scalability_metrics

main.scalability_metrics [ pass ] 899
worker[1] Valgrind report from /home/laurynas/percona/lp-mysql-server/valgrind-fixes-5.5/obj-valgrind/mysql-test/var/log/mysqld.1.err after tests:
main.scalability_metrics
--------------------------------------------------------------------------
HEAP SUMMARY:
in use at exit: 30,570,392 bytes in 215 blocks
total heap usage: 61,713 allocs, 61,498 frees, 90,904,355 bytes allocated

32 bytes in 1 blocks are definitely lost in loss record 30 of 100
   at 0x4C2CC70: calloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
   by 0x1202F43A: ???
   by 0x1202F877: ???
   by 0x1202FC88: ???
   by 0x6ED1E3: plugins_dispatch(THD*, st_plugin_int**, void*) (sql_audit.cc:457)
   by 0x6ED28A: event_class_dispatch(THD*, unsigned int, void const*) (sql_audit.cc:493)
   by 0x6EC352: general_class_handler(THD*, unsigned int, __va_list_tag*) (sql_audit.cc:90)
   by 0x6ECC92: mysql_audit_notify(THD*, unsigned int, unsigned int, ...) (sql_audit.cc:215)
   by 0x5F65CF: mysql_audit_general(THD*, unsigned int, int, char const*) (sql_audit.h:177)
   by 0x5F9DD6: dispatch_command(enum_server_command, THD*, char*, unsigned int) (sql_parse.cc:1467)
   by 0x5F7CC0: do_command(THD*) (sql_parse.cc:789)
   by 0x6F0C0D: do_handle_one_connection(THD*) (sql_connect.cc:1409)
   by 0x6F073C: handle_one_connection (sql_connect.cc:1324)
   by 0x9BBB8F: pfs_spawn_thread (pfs.cc:1015)
   by 0x525A181: start_thread (pthread_create.c:312)
   by 0x5FB230C: clone (clone.S:111)

64 bytes in 2 blocks are definitely lost in loss record 61 of 100
   at 0x4C2CC70: calloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
   by 0x1202F43A: ???
   by 0x1202FCEF: ???
   by 0x6ED1E3: plugins_dispatch(THD*, st_plugin_int**, void*) (sql_audit.cc:457)
   by 0x6ED28A: event_class_dispatch(THD*, unsigned int, void const*) (sql_audit.cc:493)
   by 0x6EC9A4: connection_class_handler(THD*, unsigned int, __va_list_tag*) (sql_audit.cc:114)
   by 0x6ECC92: mysql_audit_notify(THD*, unsigned int, unsigned int, ...) (sql_audit.cc:215)
   by 0x6F09DF: thd_prepare_connection(THD*) (sql_connect.cc:1333)
   by 0x6F0BE4: do_handle_one_connection(THD*) (sql_connect.cc:1399)
   by 0x6F073C: handle_one_connection (sql_connect.cc:1324)
   by 0x9BBB8F: pfs_spawn_thread (pfs.cc:1015)
   by 0x525A181: start_thread (pthread_create.c:312)
   by 0x5FB230C: clone (clone.S:111)

plugins_dispatch is the last function in the server code, ??? and ??? are likely to be in plugin. There is a single calloc site in the plugin source, sm_thd_data_get.

Tags:

Related branches

lp:~sergei.glushchenko/percona-server/5.5-ps-bug1334570

Merged into lp:percona-server/5.5 at revision 697

Alexey Kopytov (community): Approve on 2014-09-08

Superseded for merging into lp:percona-server/5.6

Registry Administrators: Pending requested 2014-09-01

lp:~sergei.glushchenko/percona-server/5.6-ps-bug1334570

Merged into lp:percona-server/5.5

Alexey Kopytov (community): Approve on 2014-09-08

Laurynas Biveinis (laurynas-biveinis) on 2014-06-26

tags:

added: ci valgrind

Revision history for this message

Valerii Kravchuk (valerii-kravchuk) wrote on 2014-06-26:

I can not reproduce this with 5.6.19-66.1-debug-log

Revision history for this message

Valerii Kravchuk (valerii-kravchuk) wrote on 2014-06-26:

Download full text (6.0 KiB)

It seems I've reproduced it:

openxs@ao756:~/dbs/p5.6v/mysql-test$ ./mysql-test-run --valgrind ctype_eucjpms
Logging: ./mysql-test-run --valgrind ctype_eucjpms
2014-06-26 12:50:59 24175 [Warning] Buffered warning: Changed limits: max_open_files: 1024 (requested 5000)

2014-06-26 12:50:59 24175 [Warning] Buffered warning: Changed limits: table_cache: 431 (requested 2000)

2014-06-26 12:50:59 24175 [Note] Plugin 'FEDERATED' is disabled.
2014-06-26 12:50:59 24175 [Note] Binlog end
2014-06-26 12:50:59 24175 [Note] Shutting down plugin 'CSV'
2014-06-26 12:50:59 24175 [Note] Shutting down plugin 'MyISAM'
MySQL Version 5.6.19
Turning on valgrind for all executables
Running valgrind with options " --show-reachable=yes "
Turning off --check-testcases to save time when valgrinding
Checking supported features...
- SSL connections supported
- binaries are debug compiled
Collecting tests...
Checking leftover processes...
Removing old var directory...
Creating var directory '/home/openxs/dbs/p5.6v/mysql-test/var'...
Installing system database...

==============================================================================

TEST RESULT TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
^Cmysql-test-run: *** ERROR: Got ^C signal
openxs@ao756:~/dbs/p5.6v/mysql-test$ ./mysql-test-run --valgrind scalability_metrics
Logging: ./mysql-test-run --valgrind scalability_metrics
2014-06-26 12:57:20 24244 [Warning] Buffered warning: Changed limits: max_open_files: 1024 (requested 5000)

2014-06-26 12:57:20 24244 [Warning] Buffered warning: Changed limits: table_cache: 431 (requested 2000)

2014-06-26 12:57:20 24244 [Note] Plugin 'FEDERATED' is disabled.
2014-06-26 12:57:20 24244 [Note] Binlog end
2014-06-26 12:57:20 24244 [Note] Shutting down plugin 'CSV'
2014-06-26 12:57:20 24244 [Note] Shutting down plugin 'MyISAM'
MySQL Version 5.6.19
Turning on valgrind for all executables
Running valgrind with options " --show-reachable=yes "
Turning off --check-testcases to save time when valgrinding
Checking supported features...
- SSL connections supported
- binaries are debug compiled
Collecting tests...
Checking leftover processes...
- found old pid 24208 in 'mysqld.1.pid', killing it...
process did not exist!
Removing old var directory...
Creating var directory '/home/openxs/dbs/p5.6v/mysql-test/var'...
Installing system database...

==============================================================================

TEST RESULT TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
main.scalability_metrics [ pass ] 4508
worker[1] Valgrind report from /home/openxs/dbs/p5.6v/mysql-test/var/log/mysqld.1.err after tests:
main.scalability_metrics
--------------------------------------------------------------------------
HEAP SUMMARY:
in use at exit: 68,760,941 bytes in 1,138 blocks
total heap usage: 30,828 allocs, 29,690 frees, 112,428,176 bytes ...

It seems I've reproduced it:

openxs@ao756:~/dbs/p5.6v/mysql-test$ ./mysql-test-run --valgrind ctype_eucjpms
Logging: ./mysql-test-run  --valgrind ctype_eucjpms
2014-06-26 12:50:59 24175 [Warning] Buffered warning: Changed limits: max_open_files: 1024 (requested 5000)

2014-06-26 12:50:59 24175 [Warning] Buffered warning: Changed limits: table_cache: 431 (requested 2000)

2014-06-26 12:50:59 24175 [Note] Plugin 'FEDERATED' is disabled.
2014-06-26 12:50:59 24175 [Note] Binlog end
2014-06-26 12:50:59 24175 [Note] Shutting down plugin 'CSV'
2014-06-26 12:50:59 24175 [Note] Shutting down plugin 'MyISAM'
MySQL Version 5.6.19
Turning on valgrind for all executables
Running valgrind with options " --show-reachable=yes "
Turning off --check-testcases to save time when valgrinding
Checking supported features...
 - SSL connections supported
 - binaries are debug compiled
Collecting tests...
Checking leftover processes...
Removing old var directory...
Creating var directory '/home/openxs/dbs/p5.6v/mysql-test/var'...
Installing system database...

==============================================================================

TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
^Cmysql-test-run: *** ERROR: Got ^C signal
openxs@ao756:~/dbs/p5.6v/mysql-test$ ./mysql-test-run --valgrind scalability_metrics
Logging: ./mysql-test-run  --valgrind scalability_metrics
2014-06-26 12:57:20 24244 [Warning] Buffered warning: Changed limits: max_open_files: 1024 (requested 5000)

2014-06-26 12:57:20 24244 [Warning] Buffered warning: Changed limits: table_cache: 431 (requested 2000)

2014-06-26 12:57:20 24244 [Note] Plugin 'FEDERATED' is disabled.
2014-06-26 12:57:20 24244 [Note] Binlog end
2014-06-26 12:57:20 24244 [Note] Shutting down plugin 'CSV'
2014-06-26 12:57:20 24244 [Note] Shutting down plugin 'MyISAM'
MySQL Version 5.6.19
Turning on valgrind for all executables
Running valgrind with options " --show-reachable=yes "
Turning off --check-testcases to save time when valgrinding
Checking supported features...
 - SSL connections supported
 - binaries are debug compiled
Collecting tests...
Checking leftover processes...
 - found old pid 24208 in 'mysqld.1.pid', killing it...
   process did not exist!
Removing old var directory...
Creating var directory '/home/openxs/dbs/p5.6v/mysql-test/var'...
Installing system database...

==============================================================================

TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
main.scalability_metrics                 [ pass ]   4508
worker[1] Valgrind report from /home/openxs/dbs/p5.6v/mysql-test/var/log/mysqld.1.err after tests:
 main.scalability_metrics
--------------------------------------------------------------------------
HEAP SUMMARY:
    in use at exit: 68,760,941 bytes in 1,138 blocks
  total heap usage: 30,828 allocs, 29,690 frees, 112,428,176 bytes allocated

32 bytes in 1 blocks are definitely lost in loss record 149 of 369
   at 0x4C2CC70: calloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
   by 0x14D5E3A9: ???
   by 0x14D5E7E6: ???
   by 0x14D5EBF7: ???
   by 0x774307: plugins_dispatch(THD*, st_plugin_int**, void*) (sql_audit.cc:433)
   by 0x7743AE: event_class_dispatch(THD*, unsigned int, void const*) (sql_audit.cc:469)
   by 0x773473: general_class_handler(THD*, unsigned int, __va_list_tag*) (sql_audit.cc:69)
   by 0x773DB3: mysql_audit_notify(THD*, unsigned int, unsigned int, ...) (sql_audit.cc:194)
   by 0x7EA91D: mysql_audit_general(THD*, unsigned int, int, char const*) (sql_audit.h:224)
   by 0x7EEFB3: dispatch_command(enum_server_command, THD*, char*, unsigned int) (sql_parse.cc:1865)
   by 0x7ECA55: do_command(THD*) (sql_parse.cc:1051)
   by 0x7B1976: do_handle_one_connection(THD*) (sql_connect.cc:1532)
   by 0x7B147E: handle_one_connection (sql_connect.cc:1443)
   by 0xEC9D37: pfs_spawn_thread (pfs.cc:1860)
   by 0x5CBE181: start_thread (pthread_create.c:312)
   by 0x67EF30C: clone (clone.S:111)

64 bytes in 2 blocks are definitely lost in loss record 210 of 369
   at 0x4C2CC70: calloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
   by 0x14D5E3A9: ???
   by 0x14D5EC5E: ???
   by 0x774307: plugins_dispatch(THD*, st_plugin_int**, void*) (sql_audit.cc:433)
   by 0x7743AE: event_class_dispatch(THD*, unsigned int, void const*) (sql_audit.cc:469)
   by 0x773AC5: connection_class_handler(THD*, unsigned int, __va_list_tag*) (sql_audit.cc:93)
   by 0x773DB3: mysql_audit_notify(THD*, unsigned int, unsigned int, ...) (sql_audit.cc:194)
   by 0x7B1723: thd_prepare_connection(THD*) (sql_connect.cc:1452)
   by 0x7B194D: do_handle_one_connection(THD*) (sql_connect.cc:1522)
   by 0x7B147E: handle_one_connection (sql_connect.cc:1443)
   by 0xEC9D37: pfs_spawn_thread (pfs.cc:1860)
   by 0x5CBE181: start_thread (pthread_create.c:312)
   by 0x67EF30C: clone (clone.S:111)

LEAK SUMMARY:
   definitely lost: 96 bytes in 3 blocks
   indirectly lost: 0 bytes in 0 blocks
     possibly lost: 0 bytes in 0 blocks
   still reachable: 0 bytes in 0 blocks
        suppressed: 68,760,845 bytes in 1,135 blocks

For counts of detected and suppressed errors, rerun with: -v
ERROR SUMMARY: 2 errors from 2 contexts (suppressed: 314 from 314)

valgrind_report                          [ fail ]
        Test ended at 2014-06-26 12:58:15

Valgrind reported failures at shutdown, see above

--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 4.508 of 55 seconds executing testcases

Completed: Failed 1/2 tests, 50.00% were successful.

Failing test(s): valgrind_report

The log files in var/log may give you some hint of what went wrong.

If you want to report this error, please read first the documentation
at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html

mysql-test-run: *** ERROR: there were failing test cases

Revision history for this message

Shahriyar Rzayev (rzayev-sehriyar) wrote on 2018-01-25:

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-1515

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.