| Bug #60291 | function name not included in SHOW PROFILE SOURCE output | ||
|---|---|---|---|
| Submitted: | 1 Mar 2011 12:29 | Modified: | 1 Mar 2011 16:58 |
| Reporter: | Daniël van Eeden | Email Updates: | |
| Status: | Verified | Impact on me: | |
| Category: | MySQL Server: General | Severity: | S3 (Non-critical) |
| Version: | 5.1.54, 5.1.55 | OS: | Any (Mac OS X, Linux) |
| Assigned to: | CPU Architecture: | Any | |
[1 Mar 2011 12:29]
Daniël van Eeden
[1 Mar 2011 13:05]
MySQL Verification Team
Thank you for the bug report. I was able to repeat for server 5.5 but not with 5.1 (on Windows). Which exactly version are you using?. Thanks in advance. C:\DBS>c:\dbs\5.1\bin\mysql -uroot --port=3306 --prompt="mysql 5.1 >" Welcome to the MySQL monitor. Commands end with ; or \g. Your MySQL connection id is 1 Server version: 5.1.57-Win X64-log Source distribution Copyright (c) 2000, 2010, Oracle and/or its affiliates. All rights reserved. This software comes with ABSOLUTELY NO WARRANTY. This is free software, and you are welcome to modify and redistribute it under the GPL v2 license Type 'help;' or '\h' for help. Type '\c' to clear the current input statement. mysql 5.1 >set profiling=1; Query OK, 0 rows affected (0.00 sec) mysql 5.1 >select now(); +---------------------+ | now() | +---------------------+ | 2011-03-01 10:02:57 | +---------------------+ 1 row in set (0.00 sec) mysql 5.1 >show profile source for query 1; +----------------------+----------+-----------------------+-----------------+-------------+ | Status | Duration | Source_function | Source_file | Source_line | +----------------------+----------+-----------------------+-----------------+-------------+ | starting | 0.000055 | NULL | NULL | NULL | | checking permissions | 0.000005 | check_access | .\sql_parse.cc | 5318 | | Opening tables | 0.000012 | open_tables | .\sql_base.cc | 4520 | | init | 0.000030 | mysql_select | .\sql_select.cc | 2524 | | optimizing | 0.000004 | JOIN::optimize | .\sql_select.cc | 833 | | executing | 0.000357 | JOIN::exec | .\sql_select.cc | 1780 | | end | 0.000005 | mysql_select | .\sql_select.cc | 2570 | | query end | 0.000004 | mysql_execute_command | .\sql_parse.cc | 5082 | | freeing items | 0.000107 | mysql_parse | .\sql_parse.cc | 6106 | | logging slow query | 0.000003 | log_slow_statement | .\sql_parse.cc | 1722 | | cleaning up | 0.000004 | dispatch_command | .\sql_parse.cc | 1690 | +----------------------+----------+-----------------------+-----------------+-------------+ 11 rows in set (0.00 sec)
[1 Mar 2011 14:02]
Daniël van Eeden
I've just tested it with 5.1.55 on 64-bit Linux (Download: mysql-5.1.55-linux-x86_64-glibc23.tar.gz)
mysql [localhost] {msandbox} ((none)) > set profiling=1;
Query OK, 0 rows affected (0.00 sec)
mysql [localhost] {msandbox} ((none)) > select now();
+---------------------+
| now() |
+---------------------+
| 2011-03-01 13:59:58 |
+---------------------+
1 row in set (0.00 sec)
mysql [localhost] {msandbox} ((none)) > show profile source for query 1;
+----------------------+----------+------------------+---------------+-------------+
| Status | Duration | Source_function | Source_file | Source_line |
+----------------------+----------+------------------+---------------+-------------+
| starting | 0.000134 | NULL | NULL | NULL |
| checking permissions | 0.000012 | unknown function | sql_parse.cc | 5305 |
| Opening tables | 0.000013 | unknown function | sql_base.cc | 4520 |
| init | 0.000040 | unknown function | sql_select.cc | 2520 |
| optimizing | 0.000008 | unknown function | sql_select.cc | 829 |
| executing | 0.000025 | unknown function | sql_select.cc | 1776 |
| end | 0.000009 | unknown function | sql_select.cc | 2566 |
| query end | 0.000002 | unknown function | sql_parse.cc | 5069 |
| freeing items | 0.000023 | unknown function | sql_parse.cc | 6093 |
| logging slow query | 0.000001 | unknown function | sql_parse.cc | 1709 |
| cleaning up | 0.000002 | unknown function | sql_parse.cc | 1677 |
+----------------------+----------+------------------+---------------+-------------+
11 rows in set (0.00 sec)
mysql [localhost] {msandbox} ((none)) > select version();
+-----------+
| version() |
+-----------+
| 5.1.55 |
+-----------+
1 row in set (0.00 sec)
[1 Mar 2011 14:04]
Daniël van Eeden
Reading your output there also seems to be a bug with the Source file name on Windows. (The .\ shouldn't be there). Should I create another bug report for that?
[1 Mar 2011 14:43]
Valeriy Kravchuk
Looks like it depends on compilation options. With 5.1.57 on Linux (compiled using old BUILD/compile-pentium-valgrind-max-no-ndb script) I see the same problem as reported initially. On the other hand, even 5.1.54 does not demonstrate any problem (besides .\ before the file names): mysql> exit Bye C:\Program Files\MySQL\MySQL Server 5.5\bin>mysql -uroot -proot -P3310 test Welcome to the MySQL monitor. Commands end with ; or \g. Your MySQL connection id is 3 Server version: 5.1.54-community MySQL Community Server (GPL) Copyright (c) 2000, 2010, 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. mysql> set profiling = 1; Query OK, 0 rows affected (0.08 sec) mysql> select 1; +---+ | 1 | +---+ | 1 | +---+ 1 row in set (0.00 sec) mysql> show profile source for query 1; +--------------------------------+----------+--------------------------------+-- ---------------+-------------+ | Status | Duration | Source_function | S ource_file | Source_line | +--------------------------------+----------+--------------------------------+-- ---------------+-------------+ | starting | 0.000049 | NULL | N ULL | NULL | | checking query cache for query | 0.000056 | Query_cache::send_result_to_cl | . \sql_cache.cc | 1497 | | checking permissions | 0.000039 | check_access | . \sql_parse.cc | 5291 | | Opening tables | 0.000027 | open_tables | . \sql_base.cc | 4515 | | init | 0.000018 | mysql_select | . \sql_select.cc | 2519 | | optimizing | 0.000007 | JOIN::optimize | . \sql_select.cc | 828 | | executing | 0.000018 | JOIN::exec | . \sql_select.cc | 1775 | | end | 0.000008 | mysql_select | . \sql_select.cc | 2565 | | query end | 0.000006 | mysql_execute_command | . \sql_parse.cc | 5055 | | freeing items | 0.000412 | mysql_parse | . \sql_parse.cc | 6086 | | logging slow query | 0.000004 | log_slow_statement | . \sql_parse.cc | 1709 | | cleaning up | 0.000003 | dispatch_command | . \sql_parse.cc | 1677 | +--------------------------------+----------+--------------------------------+-- ---------------+-------------+ 12 rows in set (0.06 sec)
[1 Mar 2011 16:58]
Valeriy Kravchuk
Similar script to build (BUILD/compile-pentium-debug-max), current mysql-5.5, Mac OS X, and everything works as expected: macbook-pro:5.5 openxs$ bin/mysql -uroot test Reading table information for completion of table and column names You can turn off this feature to get a quicker startup with -A Welcome to the MySQL monitor. Commands end with ; or \g. Your MySQL connection id is 53 Server version: 5.5.11-debug-log Source distribution Copyright (c) 2000, 2010, 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. mysql> set profiling=1; Query OK, 0 rows affected (0.00 sec) mysql> select now(); +---------------------+ | now() | +---------------------+ | 2011-03-01 18:51:42 | +---------------------+ 1 row in set (0.12 sec) mysql> show profile source for query 1; +----------------------+----------+-----------------------+---------------+-------------+ | Status | Duration | Source_function | Source_file | Source_line | +----------------------+----------+-----------------------+---------------+-------------+ | starting | 0.022098 | NULL | NULL | NULL | | checking permissions | 0.000035 | check_access | sql_parse.cc | 4619 | | Opening tables | 0.000036 | open_tables | sql_base.cc | 4737 | | init | 0.070469 | mysql_select | sql_select.cc | 2550 | | optimizing | 0.000026 | optimize | sql_select.cc | 863 | | executing | 0.007701 | exec | sql_select.cc | 1823 | | end | 0.000027 | mysql_select | sql_select.cc | 2586 | | query end | 0.000012 | mysql_execute_command | sql_parse.cc | 4316 | | closing tables | 0.000020 | mysql_execute_command | sql_parse.cc | 4368 | | freeing items | 0.000078 | mysql_parse | sql_parse.cc | 5508 | | logging slow query | 0.000012 | log_slow_statement | sql_parse.cc | 1450 | | cleaning up | 0.000013 | dispatch_command | sql_parse.cc | 1406 | +----------------------+----------+-----------------------+---------------+-------------+ 12 rows in set (0.04 sec) But(!) official 5.1.55 binaries show the problem: macbook-pro:mysql-5.1.55-osx10.5-x86_64 openxs$ bin/mysql -uroot testWelcome to the MySQL monitor. Commands end with ; or \g. Your MySQL connection id is 1 Server version: 5.1.55 MySQL Community Server (GPL) Copyright (c) 2000, 2010, Oracle and/or its affiliates. All rights reserved. This software comes with ABSOLUTELY NO WARRANTY. This is free software, and you are welcome to modify and redistribute it under the GPL v2 license Type 'help;' or '\h' for help. Type '\c' to clear the current input statement. mysql> set profiling=1; Query OK, 0 rows affected (0.00 sec) mysql> select now(); +---------------------+ | now() | +---------------------+ | 2011-03-01 18:55:48 | +---------------------+ 1 row in set (0.00 sec) mysql> show profile source for query 1; +----------------------+----------+------------------+---------------+-------------+ | Status | Duration | Source_function | Source_file | Source_line | +----------------------+----------+------------------+---------------+-------------+ | starting | 0.000085 | NULL | NULL | NULL | | checking permissions | 0.000006 | unknown function | sql_parse.cc | 5305 | | Opening tables | 0.000008 | unknown function | sql_base.cc | 4520 | | init | 0.000039 | unknown function | sql_select.cc | 2520 | | optimizing | 0.000003 | unknown function | sql_select.cc | 829 | | executing | 0.000018 | unknown function | sql_select.cc | 1776 | | end | 0.000004 | unknown function | sql_select.cc | 2566 | | query end | 0.000002 | unknown function | sql_parse.cc | 5069 | | freeing items | 0.000022 | unknown function | sql_parse.cc | 6093 | | logging slow query | 0.000002 | unknown function | sql_parse.cc | 1709 | | cleaning up | 0.000003 | unknown function | sql_parse.cc | 1677 | +----------------------+----------+------------------+---------------+-------------+ 11 rows in set (0.00 sec) So, there is definitely some bug in the process of building official binaries.
