| Bug #16886 | mysqladmin reports incorrect count for slow queries, opened tables | ||
|---|---|---|---|
| Submitted: | 29 Jan 2006 23:18 | Modified: | 22 May 2006 14:25 |
| Reporter: | Chuck Tessein | Email Updates: | |
| Status: | Duplicate | Impact on me: | |
| Category: | MySQL Server: Command-line Clients | Severity: | S2 (Serious) |
| Version: | 5.0.18 | OS: | Linux (Linux) |
| Assigned to: | CPU Architecture: | Any | |
[29 Jan 2006 23:18]
Chuck Tessein
[30 Jan 2006 9:34]
Valeriy Kravchuk
Thank you for a problem report. Can you, please, send the results of mysqladmin --version command and the exact sequence of steps to demonstrate the problem?
[30 Jan 2006 12:52]
Chuck Tessein
# /usr/local/mysql/bin/mysqladmin --version /usr/local/mysql/bin/mysqladmin Ver 8.41 Distrib 5.0.18, for unknown-linux-gnu on x86_64
[30 Jan 2006 13:05]
Chuck Tessein
To replicate on a server with slow queries: # /usr/local/mysql/bin/mysqladmin --user=x --password=x status Uptime: 85496 Threads: 153 Questions: 13980315 Slow queries: 0 Opens: 0 Flush tables: 2 Open tables: 996 Queries per second avg: 163.520 # /usr/local/mysql/bin/mysqladmin --user=x --password=x extended-status +-----------------------------------+-------------+ | Variable_name | Value | +-----------------------------------+-------------+ | Aborted_clients | 312 | | Aborted_connects | 2 | . . . | Not_flushed_delayed_rows | 68 | | Open_files | 1441 | | Open_streams | 0 | | Open_tables | 996 | | Opened_tables | 1547 | | Qcache_free_blocks | 97 | | Qcache_free_memory | 354733176 | . . . | Slave_running | OFF | | Slow_launch_threads | 0 | | Slow_queries | 1371 | | Sort_merge_passes | 0 | | Sort_range | 1577034 | . . . | Threads_cached | 115 | | Threads_connected | 162 | | Threads_created | 273 | | Threads_running | 2 | | Uptime | 85341 | +-----------------------------------+-------------+ ---- [output truncated to save space].
[30 Jan 2006 13:41]
Valeriy Kravchuk
Verified just as described on latest 5.0.19-BK (ChangeSet@1.2075.1.1, 2006-01-27 20:27:10+01:00) on Linux: openxs@suse:~/dbs/5.0> bin/mysqld_safe --log-slow-queries & [1] 9279 WARNING: Found /home/openxs/dbs/5.0/var/my.cnf Datadir is deprecated place for my.cnf, please move it to /home/openxs/dbs/5.0 openxs@suse:~/dbs/5.0> Starting mysqld daemon with databases from /home/openxs/dbs/5.0/var openxs@suse:~/dbs/5.0> 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 3 to server version: 5.0.19-log Type 'help;' or '\h' for help. Type '\c' to clear the buffer. mysql> select sleep(15); +-----------+ | sleep(15) | +-----------+ | 0 | +-----------+ 1 row in set (15.04 sec) mysql> select sleep(15); +-----------+ | sleep(15) | +-----------+ | 0 | +-----------+ 1 row in set (15.00 sec) mysql> exit Bye openxs@suse:~/dbs/5.0> cat var/suse-slow.log /home/openxs/dbs/5.0/libexec/mysqld, Version: 5.0.19-log. started with: Tcp port: 0 Unix socket: (null) Time Id Command Argument # Time: 060128 10:17:03 # User@Host: root[root] @ localhost [] # Query_time: 15 Lock_time: 0 Rows_sent: 1 Rows_examined: 0 use test; select sleep(15); # Time: 060128 10:18:12 # User@Host: root[root] @ localhost [] # Query_time: 15 Lock_time: 0 Rows_sent: 1 Rows_examined: 0 select sleep(15); openxs@suse:~/dbs/5.0> bin/mysqladmin -uroot status Uptime: 165 Threads: 1 Questions: 8 Slow queries: 0 Opens: 0 Flush tables: 1 Open tables: 8 Queries per second avg: 0.048 openxs@suse:~/dbs/5.0> bin/mysqladmin -uroot extended-status | grep -i slow | Slow_launch_threads | 0 | | Slow_queries | 2 | So, there is a bug.
[25 Feb 2006 0:43]
Bruce Dembecki
I think this should be reclassified as a Server issue, not a client issue... I was going to report something similar mysqlf, but found this bug first... My data basically supports that the server isn't handling the slow counts well... My console output shows first a slow query, the the variable statements showing slow logging is on and set to 10 seconds, followed by a show status showing 0 slow queries, followed by the status command showing my client version, server version, a seven day uptime, and again, a zero slow log counter on the status window, and finally the tail of the slow log, which shows this queries and others were logged in the slow query log. This of course means that there are slow queries, but they are not appearing in our slow query counters which is what we usually use to gauge how the server is performing. It seems this information is now totally wrong and we need to come up with a new way to evaluate if our server is doing what we want it to. While it is included int he output below, I just wanted to state here we are using MySQL 5.0.17a Pro Certified and running under OS X. Best Regards, Bruce mysql> select count(*) from lwStatsThread; +----------+ | count(*) | +----------+ | 3457995 | +----------+ 1 row in set (21.07 sec) mysql> show variables like 'lo%'; +---------------------------------+-----------------------+ | Variable_name | Value | +---------------------------------+-----------------------+ | local_infile | ON | | locked_in_memory | OFF | | log | OFF | | log_bin | ON | | log_bin_trust_function_creators | OFF | | log_error | /var/mysql/mysql1.err | | log_slave_updates | ON | | log_slow_queries | ON | | log_warnings | 1 | | long_query_time | 10 | | low_priority_updates | OFF | | lower_case_file_system | OFF | | lower_case_table_names | 0 | +---------------------------------+-----------------------+ 13 rows in set (0.00 sec) mysql> show status like "Slow%"; +---------------------+-------+ | Variable_name | Value | +---------------------+-------+ | Slow_launch_threads | 0 | | Slow_queries | 0 | +---------------------+-------+ 2 rows in set (0.05 sec) mysql> status -------------- mysql Ver 14.12 Distrib 5.0.17a, for apple-darwin8.2.0 (powerpc) using readline 5.0 Connection id: 230259 Current database: jive_ebay_us Current user: engineering@localhost SSL: Not in use Current pager: stdout Using outfile: '' Using delimiter: ; Server version: 5.0.17a-pro-gpl-cert-log Protocol version: 10 Connection: Localhost via UNIX socket Server characterset: utf8 Db characterset: utf8 Client characterset: utf8 Conn. characterset: utf8 UNIX socket: /tmp/mysql.sock Uptime: 7 days 14 hours 38 min 3 sec Threads: 128 Questions: 63097078 Slow queries: 0 Opens: 0 Flush tables: 1 Open tables: 523 Queries per second avg: 95.968 -------------- mysql> exit [data1:~] bruce# tail -30 /var/mysql/mysql1.slow Tcp port: 3306 Unix socket: /tmp/mysql.sock Time Id Command Argument /usr/local/mysql/bin/mysqld, Version: 5.0.17a-pro-gpl-cert-log. started with: Tcp port: 3306 Unix socket: /tmp/mysql.sock Time Id Command Argument /usr/local/mysql/bin/mysqld, Version: 5.0.17a-pro-gpl-cert-log. started with: Tcp port: 3306 Unix socket: /tmp/mysql.sock Time Id Command Argument # Time: 060224 12:10:13 # User@Host: ebusdb[ebusdb] @ apps9.back.liveworld.com [10.1.3.89] # Query_time: 18 Lock_time: 0 Rows_sent: 0 Rows_examined: 0 use jive_ebay_us; DELETE FROM jiveReadTracker WHERE readDate < 1138219200000; # User@Host: ebusdb[ebusdb] @ apps1.back.liveworld.com [10.1.3.81] # Query_time: 13 Lock_time: 0 Rows_sent: 0 Rows_examined: 0 INSERT INTO jiveReadTracker (userID, objectType, objectID, readDate) VALUES (73928,1,1000228566,1140782614918); # User@Host: ebusdb[ebusdb] @ apps1.back.liveworld.com [10.1.3.81] # Query_time: 11 Lock_time: 0 Rows_sent: 0 Rows_examined: 0 UPDATE jiveReadTracker SET readDate=1140811467902 WHERE userID=400033838 AND objectType=1 AND objectID=1000230556; # User@Host: ebusdb[ebusdb] @ apps1.back.liveworld.com [10.1.3.81] # Query_time: 11 Lock_time: 0 Rows_sent: 0 Rows_examined: 0 UPDATE jiveReadTracker SET readDate=1140811360028 WHERE userID=21041 AND objectType=1 AND objectID=1000230524; /usr/local/mysql/bin/mysqld, Version: 5.0.17a-pro-gpl-cert-log. started with: Tcp port: 3306 Unix socket: /tmp/mysql.sock Time Id Command Argument # Time: 060224 15:22:51 # User@Host: engineering[engineering] @ localhost [] # Query_time: 21 Lock_time: 0 Rows_sent: 1 Rows_examined: 3457995 use jive_ebay_us; select count(*) from lwStatsThread; [data1:~] bruce#
[22 May 2006 14:25]
Iggy Galarza
Duplicate of Bug #18669 which was reported later but is "in progress" already.
[24 Jan 2008 21:04]
Isaac Venn
Running into a very similar problem on version 5.0.41-community on Redhat ES 4u5: #-(0)> mysql -p -e "show status like '%opened%'" Enter password: +---------------+-------+ | Variable_name | Value | +---------------+-------+ | Opened_tables | 0 | +---------------+-------+ #-(root@server)-(~)-# #-(0)> mysql -p -e "show status like '%slow_q%'" Enter password: +---------------+-------+ | Variable_name | Value | +---------------+-------+ | Slow_queries | 0 | +---------------+-------+ #-(root@server)-(~)-# #-(0)> mysqladmin -p status Enter password: Uptime: 4117680 Threads: 35 Questions: 330144195 Slow queries: 10165392 Opens: 12505 Flush tables: 114 Open tables: 171 Queries per second avg: 80.177
