Bug #59273 | show profile source doesn't show Source_function or truncates Source_file | ||
---|---|---|---|
Submitted: | 4 Jan 2011 10:14 | Modified: | 1 Mar 2011 1:34 |
Reporter: | Shane Bester (Platinum Quality Contributor) | Email Updates: | |
Status: | Closed | Impact on me: | |
Category: | MySQL Server: General | Severity: | S3 (Non-critical) |
Version: | 5.1.54, 5.5.8 | OS: | Any |
Assigned to: | Tor Didriksen | CPU Architecture: | Any |
[4 Jan 2011 10:14]
Shane Bester
[4 Jan 2011 10:18]
MySQL Verification Team
full output attached to avoid wrapping.
Attachment: bug59273_full_uncut_output.txt (text/plain), 3.92 KiB.
[4 Jan 2011 10:22]
Marc ALFF
Analysis ======== Looks related to how the build is done with CMAKE, which uses: - absolute file names (/path/to/code.cc) - instead of relative file names (code.cc), which in turn affects __FILE__
[12 Jan 2011 13:48]
Daniël van Eeden
In 5.5.8 the SHOW ENGINE INNODB output shows full paths in the SEMAPHORES section. It makes the output less readable. Is this also related to the switch from autotools to cmake? ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 2720, signal count 2710 --Thread 2836126576 has waited at /export/home/pb2/build/sb_0-2629600-1291401802.22/mysqlcom-pro-5.5.8/storage/innobase/log/log0log.c line 2026 for 1.00 seconds the semaphore: S-lock on RW-latch at 0x9a082b8 created in file /export/home/pb2/build/sb_0-2629600-1291401802.22/mysqlcom-pro-5.5.8/storage/innobase/log/log0log.c line 832 a writer (thread id 2836126576) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file /export/home/pb2/build/sb_0-2629600-1291401802.22/mysqlcom-pro-5.5.8/storage/innobase/log/log0log.c line 2049 Last time write locked in file /export/home/pb2/build/sb_0-2629600-1291401802.22/mysqlcom-pro-5.5.8/storage/innobase/log/log0log.c line 1846 --Thread 2813647728 has waited at /export/home/pb2/build/sb_0-2629600-1291401802.22/mysqlcom-pro-5.5.8/storage/innobase/include/log0log.ic line 405 for 1.00 seconds the semaphore: Mutex at 0x9a08194 created file /export/home/pb2/build/sb_0-2629600-1291401802.22/mysqlcom-pro-5.5.8/storage/innobase/log/log0log.c line 771, lock var 1 waiters flag 1 Mutex spin waits 205506, rounds 342214, OS waits 1764 RW-shared spins 723, rounds 18436, OS waits 611 RW-excl spins 254, rounds 5388, OS waits 169 Spin rounds per wait: 1.67 mutex, 25.50 RW-shared, 21.21 RW-excl
[12 Jan 2011 13:57]
Daniël van Eeden
And the full path is also used for this assertion failure in buf0lru.c:892 110112 14:53:02 InnoDB: ERROR: over 95 percent of the buffer pool is occupied by InnoDB: lock heaps or the adaptive hash index! Check that your InnoDB: transactions do not set too many row locks. InnoDB: Your buffer pool size is 127 MB. Maybe you should make InnoDB: the buffer pool bigger? InnoDB: We intentionally generate a seg fault to print a stack trace InnoDB: on Linux! 110112 14:53:02 InnoDB: Assertion failure in thread 2836126576 in file /export/home/pb2/build/sb_0-2629600-1291401802.22/mysqlcom-pro-5.5.8/storage/innobase/buf/buf0lru.c line 892 InnoDB: We intentionally generate a memory trap. InnoDB: Submit a detailed bug report to http://bugs.mysql.com. InnoDB: If you get repeated assertion failures or crashes, even InnoDB: immediately after the mysqld startup, there may be InnoDB: corruption in the InnoDB tablespace. Please refer to InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-recovery.html InnoDB: about forcing recovery.
[12 Jan 2011 14:59]
Daniël van Eeden
And it is also affecting 'SHOW ENGINE INNODB MUTEX' mysql> SHOW ENGINE INNODB MUTEX; +--------+------------------------------------------------------------------------------------------------------------------+---------------+ | Type | Name | Status | +--------+------------------------------------------------------------------------------------------------------------------+---------------+ | InnoDB | /export/home/pb2/build/sb_0-2629600-1291401802.22/mysqlcom-pro-5.5.8/storage/innobase/log/log0log.c:771 | os_waits=1418 | | InnoDB | /export/home/pb2/build/sb_0-2629600-1291401802.22/mysqlcom-pro-5.5.8/storage/innobase/buf/buf0buf.c:1243 | os_waits=7 | | InnoDB | /export/home/pb2/build/sb_0-2629600-1291401802.22/mysqlcom-pro-5.5.8/storage/innobase/buf/buf0buf.c:1208 | os_waits=789 | | InnoDB | /export/home/pb2/build/sb_0-2629600-1291401802.22/mysqlcom-pro-5.5.8/storage/innobase/fil/fil0fil.c:1559 | os_waits=50 | | InnoDB | /export/home/pb2/build/sb_0-2629600-1291401802.22/mysqlcom-pro-5.5.8/storage/innobase/srv/srv0srv.c:996 | os_waits=194 | | InnoDB | combined /export/home/pb2/build/sb_0-2629600-1291401802.22/mysqlcom-pro-5.5.8/storage/innobase/buf/buf0buf.c:898 | os_waits=2 | | InnoDB | /export/home/pb2/build/sb_0-2629600-1291401802.22/mysqlcom-pro-5.5.8/storage/innobase/log/log0log.c:832 | os_waits=162 | | InnoDB | combined /export/home/pb2/build/sb_0-2629600-1291401802.22/mysqlcom-pro-5.5.8/storage/innobase/buf/buf0buf.c:898 | os_waits=1667 | +--------+------------------------------------------------------------------------------------------------------------------+---------------+ 8 rows in set (0.00 sec)
[18 Jan 2011 15:28]
Tor Didriksen
http://www.cmake.org/cmake/help/cmake-2-8-docs.html#variable:CMAKE_USE_RELATIVE_PATHS # CMAKE_USE_RELATIVE_PATHS: Use relative paths (May not work!). Cmake documentation warns against using relative paths. So I guess we have to resort to doing base_name(__FILE__) on things that are user-facing. We do not want the overhead of base_name whenever __FILE__ is stored (in e.g. in rw_lock_struct), so it should be done before presenting results to the user. For SHOW ENGINE INNODB MUTEX; this patch should work (but there are lots more places...) === modified file 'storage/innobase/handler/ha_innodb.cc' --- storage/innobase/handler/ha_innodb.cc 2011-01-13 07:33:03 +0000 +++ storage/innobase/handler/ha_innodb.cc 2011-01-18 15:07:08 +0000 @@ -9731,7 +9731,7 @@ } buf1len = my_snprintf(buf1, sizeof buf1, "%s:%lu", - lock->cfile_name, (ulong) lock->cline); + base_name(lock->cfile_name), (ulong) lock->cline); buf2len = my_snprintf(buf2, sizeof buf2, "os_waits=%lu", (ulong) lock->count_os_wait);
[19 Jan 2011 7:46]
Roel Van de Paar
See bug #58999
[20 Jan 2011 15:09]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/129288 3271 Tor Didriksen 2011-01-20 Bug #59273 show profile source doesn't show Source_function or truncates Source_file Fixed the 'show profile source' part of the bug. Leaving SHOW ENGINE INNODB MUTEX to a separate patch. @ sql/sql_class.cc Use base_name(calling_file) for dbug trace and profiling.
[27 Jan 2011 13:25]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/129760 3280 Tor Didriksen 2011-01-27 Bug #59273 show profile source doesn't show Source_function or truncates Source_file Fixed the 'show profile source' part of the bug. Leaving SHOW ENGINE INNODB MUTEX to a separate patch. @ sql/sql_class.cc Use base_name(calling_file) for dbug trace and profiling.
[27 Jan 2011 13:47]
Bugs System
Pushed into mysql-trunk 5.6.2 (revid:tor.didriksen@oracle.com-20110127134628-9cakw9celrequj4i) (version source revid:tor.didriksen@oracle.com-20110127134628-9cakw9celrequj4i) (merge vers: 5.6.2) (pib:24)
[27 Jan 2011 13:47]
Bugs System
Pushed into mysql-5.5 5.5.10 (revid:tor.didriksen@oracle.com-20110127132527-w0so1o5tzi9o6vlz) (version source revid:tor.didriksen@oracle.com-20110127132527-w0so1o5tzi9o6vlz) (merge vers: 5.5.10) (pib:24)
[1 Mar 2011 1:34]
Paul DuBois
Noted in 5.5.10, 5.6.2 changelogs. SHOW PROFILE could truncate source file names or fail to show function names. CHANGESET - http://lists.mysql.com/commits/129760
[1 Mar 2011 9:28]
Daniël van Eeden
As far as I know it's fixed only for 5.5 and 5.6, not for 5.1 which was also requested.
[1 Mar 2011 9:29]
Daniël van Eeden
I also believe that the SHOW ENGINE INNODB MUTEX output is not fixed?
[1 Mar 2011 11:14]
Davi Arnaut
The problem does not exist in 5.1. The InnoDB issue is a separate one.
[14 Jul 2011 18:41]
MySQL Verification Team
The fix for this leads us to: Defect #12756017 PROFILING: SET_THD_PROC_INFO DOES NOT NEED TO CALL DIRNAME_LENGTH EACH TIME