[MDEV-18817] MariaDB 10.1.29 slow query not working Created: 2019-03-05  Updated: 2019-03-09  Resolved: 2019-03-09

Status: Closed
Project: MariaDB Server
Component/s: Configuration
Affects Version/s: None
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: timchou Assignee: Unassigned
Resolution: Not a Bug Votes: 0
Labels: None
Environment:

Ubuntu 18.10;MariaDB 10.1.29;



 Description   

Hi

My MariaDB 10.1.29 is not logging slow query.

Here are config:

| log_slow_admin_statements | OFF                             |
| log_slow_filter           |                                 |
| log_slow_rate_limit       | 1000                            |
| log_slow_slave_statements | OFF                             |
| log_slow_verbosity        |                                 |
| slow_launch_time          | 2                               |
| slow_query_log            | ON                              |
| slow_query_log_file       | /var/log/mysql/mariadb-slow.log |
| long_query_time                                        | 5.000000 |
| log_output                 | FILE,TABLE |

and in status command ,I can see slow queries are more than 0:

MariaDB [(none)]> status
--------------
mysql  Ver 15.1 Distrib 10.1.29-MariaDB, for debian-linux-gnu (x86_64) using readline 5.2
 
Connection id:		67
Current database:
Current user:		root@localhost
SSL:			Not in use
Current pager:		stdout
Using outfile:		''
Using delimiter:	;
Server:			MariaDB
Server version:		10.1.29-MariaDB-6ubuntu2 Ubuntu 18.10
Protocol version:	10
Connection:		Localhost via UNIX socket
Server characterset:	utf8mb4
Db     characterset:	utf8mb4
Client characterset:	utf8mb4
Conn.  characterset:	utf8mb4
UNIX socket:		/var/run/mysqld/mysqld.sock
Uptime:			1 hour 8 min 5 sec
 
Threads: 28  Questions: 166151  Slow queries: 701  Opens: 196  Flush tables: 1  Open tables: 190  Queries per second avg: 40.673

but in slow log file and in mysql.slow_log,there is nothing at all.

anyone can give some help?

Thx!



 Comments   
Comment by Daniel Black [ 2019-03-05 ]

Because of log_slow_rate_limit there is a 1/1000 chance that a slow query won't be logged.

Is there anything in the mysql error log (`journalctl -u mariadb.service`) about not being able to create the file? What is the permission on /var/log/mysql/? If you lsof -p $(pidof mysqld) | grep /var/log is the slow query log there? Does it have '(deleted)' on that same line (which would indicate a logrotate problem)?

Comment by timchou [ 2019-03-05 ]

Hi Daniel

Thanks for your reply

mysql error log has no relative errors:

2019-03-05  2:23:34 140593162477504 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2019-03-05  2:23:34 140593162477504 [Note] InnoDB: The InnoDB memory heap is disabled
2019-03-05  2:23:34 140593162477504 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2019-03-05  2:23:34 140593162477504 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2019-03-05  2:23:34 140593162477504 [Note] InnoDB: Compressed tables use zlib 1.2.11
2019-03-05  2:23:34 140593162477504 [Note] InnoDB: Using Linux native AIO
2019-03-05  2:23:34 140593162477504 [Note] InnoDB: Using SSE crc32 instructions
2019-03-05  2:23:34 140593162477504 [Note] InnoDB: Initializing buffer pool, size = 4.0G
2019-03-05  2:23:34 140593162477504 [Note] InnoDB: Completed initialization of buffer pool
2019-03-05  2:23:34 140593162477504 [Note] InnoDB: Highest supported file format is Barracuda.
2019-03-05  2:23:34 140593162477504 [Note] InnoDB: 128 rollback segment(s) are active.
2019-03-05  2:23:34 140593162477504 [Note] InnoDB: Waiting for purge to start
2019-03-05  2:23:34 140593162477504 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.36-82.2 started; log sequence number 14517640669
2019-03-05  2:23:34 140593162477504 [Note] Plugin 'FEEDBACK' is disabled.
2019-03-05  2:23:34 140587967706880 [Note] InnoDB: Dumping buffer pool(s) not yet started
2019-03-05  2:23:34 140593162477504 [Note] Server socket created on IP: '10.8.96.4'.
2019-03-05  2:23:34 140593162477504 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.1.29-MariaDB-6ubuntu2'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Ubuntu 18.10
2019-03-05  2:23:34 140593103030016 [Warning] IP address '10.8.96.3' could not be resolved: Name or service not known

/var/log/mysql's permission is ok I think:

drwxr-s---   2 mysql     adm                  4096 Mar  5 02:12 mysql/

db01@/var/log/mysql$  lsof -p $(pidof mysqld) | grep /var/log
mysqld  31974 mysql    1w   REG              252,1       5447   264178 /var/log/mysql/error.log
mysqld  31974 mysql    2w   REG              252,1       5447   264178 /var/log/mysql/error.log
mysqld  31974 mysql   44w   REG              252,1       1098   256079 /var/log/mysql/mariadb-slow.log

and you said "Because of log_slow_rate_limit there is a 1/1000 chance that a slow query won't be logged."
But in status command ,I can see hundreds slow queries, but in slow query log,there is nothing at all TAT

Comment by Elena Stepanova [ 2019-03-09 ]

With log_slow_rate_limit=1000, only one query out of 1000 is logged.

Generated at Thu Feb 08 08:46:57 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.