Pmm slow query log location

Description:

Hi I just installed a new Percona Xtradb Cluster 8 monitored by pmm. For the query analytics I want to use slow query log. In /var/log/messages pmm seems to try to read slow query logs from /var/lib/mysql/{server-name.log} because I have a lot of this error :

pmm-agent[77995]: #033[31mERRO#033[0m[2023-08-31T11:28:30.831-04:00] Failed to start reader for file /var/lib/mysql/{server_name}.log.000001: open /var/lib/mysql/{server_name}.log.000001: no such file or directory. #033[31magentID#033[0m=/agent_id/47b6b201-902b-45bd-aab8-c8cabc542bf6 #033[31mcomponent#033[0m=agent-builtin #033[31mtype#033[0m=qan_mysql_slowlog_agent

My slow query log is in /var/log/mysql.
I could not find in the documentation how to change the location in pmm client config.

Version:

pmm-client 2.32.0

PMM should connect to your MySQL server and run “SHOW GLOBAL VARIABLES LIKE ‘slow_query_log_file’” and that is the location it reads from. Can you run that manually and confirm the location? Is your slow query log enabled? What is the value of long_query_time?

mysql> SHOW GLOBAL VARIABLES LIKE 'slow_query_log';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| slow_query_log | ON    |
+----------------+-------+
1 row in set (0.01 sec)

mysql> SHOW GLOBAL VARIABLES LIKE 'long_query_time';
+-----------------+----------+
| Variable_name   | Value    |
+-----------------+----------+
| long_query_time | 0.200000 |
+-----------------+----------+
1 row in set (0.00 sec)

Thank for your reply I see that my variable slow_query_log_file does not have the same value as in my configuration file so pmm reads it OK. I will try to understand why the value in my configuration file is not read.

I have a strange behaviour where my config file say slow_query_log_file=/var/log/mysql/mysqld-slow.log but the show global variables like ‘%slow_query_log_file%’ ; show me the default value mysql> show global variables like ‘%slow_query_log_file%’
→ ;
±--------------------±------------------------------------------+
| Variable_name | Value |
±--------------------±------------------------------------------+
| slow_query_log_file | /var/lib/mysql/servername.log.000001 |
±--------------------±------------------------------------------+

When I check an lsof I see that mysql is writing to /var/log/mysql/mysqld-slow.log
Did you ever see that ? Should i post it in Percona Xtradb Cluster forum ?

Just fix it so that it matches what is currently happening:

SET GLOBAL slow_query_log_file = '/var/log/mysql/mysqld-slow.log';
FLUSH SLOW LOGS;

And also check your my.cnf and ensure the parameter matches there too.

Hi yes I can do that but when the instance reboot same problem. Maybe my other anwser is not clear enough. /etc/my.cnf setting is OK, mysql write to the correct file but the show global variables like ‘%slow_query_log_file%’ ; always return the default value even if mysql does not write there! If I do ```
SET GLOBAL slow_query_log_file = ‘/var/log/mysql/mysqld-slow.log’; it correct the show variables result but if the instance reboot I have the same problem. Could it be a bug ?

Please paste your entire /etc/my.cnf file here. This is highly unlikely a bug; more likely this is config issue.

Here is the complete file content without ip adress, Thanks a lot for your help.

cat /etc/my.cnf
#
# Ansible managed
#

# Template my.cnf for PXC
# Edit to your requirements.
[client]
socket=/var/lib/mysql/mysql.sock

[mysqld]
default-authentication-plugin=mysql_native_password
server-id=1
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
log-error=/var/log/mysql/mysqld.log
log-error-verbosity=3
pid-file=/var/run/mysqld/mysqld.pid
log-bin
binlog_format=ROW
binlog_expire_logs_seconds=604800
binlog_space_limit=26843545600
binlog_cache_size=204800

slow_query_log=ON
long_query_time=0
log_slow_rate_limit=100
log_slow_rate_type=query
log_slow_verbosity=full
log_slow_admin_statements=ON
slow_query_log_always_write_time=1
slow_query_log_use_global_control=all
innodb_monitor_enable=all
userstat=1
slow_query_log_file=/var/log/mysql/mysqld-slow.log
log_queries_not_using_indexes=0
max_slowlog_size=500M
max_slowlog_files=10


symbolic-links=0

default_storage_engine=InnoDB
innodb_autoinc_lock_mode=2
innodb_buffer_pool_size=16823M
transaction-isolation=READ-COMMITTED
table_open_cache=3000
open_files_limit=6000
tmp_table_size=157286400
max_heap_table_size=157286400
enforce-gtid-consistency=ON
gtid-mode=ON
innodb_log_file_size=524288000
innodb_flush_method=O_DIRECT
innodb_flush_log_at_trx_commit = 0
innodb_print_all_deadlocks=ON
innodb_stats_persistent_sample_pages=100
log_timestamps=SYSTEM
max_connections=400

local-infile=0
skip-grant-tables=FALSE


skip_name_resolve=ON
secure_file_priv=/usr/local/ul/secfiledir
secure_log_path=/var/log/mysql

pxc-encrypt-cluster-traffic=OFF

######## wsrep ###############
wsrep_provider=/usr/lib64/galera4/libgalera_smm.so
wsrep_provider_options="gcache.size=10240M; gcache.page_size=128M; cert.log_conflicts=YES; gcs.fc_limit=10; gcs.fc_factor=0.8; pc.weight=1"
wsrep_cluster_name=pxc8-dv
#wsrep_cluster_address=gcomm://
wsrep_cluster_address=gcomm://xx.xx.xx.xx,x.x.x.xx,xx.x.xx.x
wsrep_node_name=ul-mys-dv-nod20
wsrep_node_address=xx.xx.xx.xx
wsrep_sst_method=xtrabackup-v2

wsrep_retry_autocommit=4
pxc_strict_mode=ENFORCING
wsrep_applier_threads=8

[xtrabackup]
tmpdir=/tmpxtrabackup

[mysqld_safe]
malloc-lib=/usr/lib64/libjemalloc.so.1

Ok The config looks good.

You say that when you restart MySQL, the value of slow_query_log_file is reset to ‘var/lib/mysql/servername.log.000001’ ? That filename pattern looks like a typical binary log filename, not a slow log.

I don’t think the PMM agent changes this parameter, but it might. Can you please remove the agent from this host completely. Then restart MySQL and see if the parameter changes again.

You say that when you restart MySQL, the value of slow_query_log_file is reset to ‘var/lib/mysql/servername.log.000001’

Yes for what I see in the mysql doc that’s the default value of the parameter.
I tried to remove pmm2-client and restart and same behaviour.
I will try with a basic my.cnf file to see if something wrong with my config file…

Where do you see that? This is the link to the default value:
https://dev.mysql.com/doc/refman/8.0/en/server-system-variables.html#sysvar_slow_query_log_file

As you can see, the 000001 is not the default value of the slow query log.

I don’t know for the 000001 but I found the problem the problem is this parameter :
max_slowlog_size=500M
When I remove this parameter everything is OK. Everything is also OK if I remove the M and i put :
max_slowlog_size=500

So the “M” is the problem . Looks Like a bug to me because there is nothing in the logfile, mysql write the slowquery log to the right place but the valeu show in : show global variables like ‘%slow_query_log_file%’; is not the right value when the value of max_slowlog_size is a wrong value

https://docs.percona.com/percona-server/8.0/flexibility/slowlog_rotation.html

Looks like this was a recently added feature, specific to Percona.

If you limit the size and this feature is enabled, the server renames the slow query log file to slow_query_log_file.000001

So perhaps this is a bug with the implementation of this new feature with regards to ‘slow_query_log_file’ variable not being updated when the slow log is rotated.

Glad you found the issue. I’ll see if I can dedicate some time to testing this more thoroughly and file an official bug report.

Yes it seems that if you put a wrong value for max_slowlog_size there is a bug with the value of slow_query_log_file global variable
FYI : I run :
Server version: 8.0.32-24.2 Percona XtraDB Cluster (GPL), Release rel24, Revision 2119e75, WSREP version 26.1.4.3
On Redhat 9

Hi i also think that documentation is wrong, when you put max_slowlog_size=1073741824 like the documentation say you hit the same bug. I tried different values, 2048 works but not 4096. I’m done for today enough testing for now.

Thanks for the testing. I’ve sent this forum post to our engineering team to try and find out who implemented that feature.

Ok I found other bugs with the feature and the docs, seems the minimum and maximum value in the doc are not good. And even if we put a value that work pmm does not check the right file

Sorry for bumping this (relatively) old thread, but are there any updates? I’m facing the same issue on 8.0.35-27.1 still