Link to home
Start Free TrialLog in
Avatar of Faith Victory
Faith VictoryFlag for United States of America

asked on

MySQL slow log not logging entries

I have an issue in mariadb running in centos where the slow query log does not log entries until you go in daily, disable and re-enable the slow log.

**You go in today and run SET GLOBAL slow_query_log = 1;

**You check that it is enabled by running SHOW GLOBAL VARIABLES LIKE 'slow_%';

**You check queries are being logged after running the above.

**You come in tomorrow, check the log, no entries

**You repeat the above command again and it is enable but nothing is logged until you SET GLOBAL slow_query_log = 0; and reset it back to SET GLOBAL slow_query_log = 1;

**Now it would log just for that day.

**come the next day, nothing in the slow log. Repeat the above command over again and it would log entries for that day.

IT team are using Ansible and logrotate is in place. Could it be that it is not properly flushing the file after rotation? or Is Ansible changing conf daily? Or is mariadb writing to a stale file descriptor?


***slow log output: FILE


[***********@itv-mysql01 ~]$ cat /etc/logrotate.conf


# see "man logrotate" for details

# rotate log files weekly

weekly


# keep 4 weeks worth of backlogs

rotate 4


# create new (empty) log files after rotating old ones

create


# use date as a suffix of the rotated file

dateext


# uncomment this if you want your log files compressed

#compress


# RPM packages drop log rotation information into this directory

include /etc/logrotate.d


# no packages own wtmp and btmp -- we'll rotate them here

/var/log/wtmp {

    monthly

    create 0664 root utmp

        minsize 1M

    rotate 1

}

/var/log/btmp {

    missingok

    monthly

    create 0600 root utmp

    rotate 1

}



Please suggestions are welcome to arrive at a permitting solution 

Avatar of Philip Politowicz, Ph.D.
Philip Politowicz, Ph.D.
Flag of United States of America image

I don't think logrotate is the problem. Do you have any slow query log config settings in my.cnf? If the database is being restarted daily, you want to set at least the following in the /etc/my.cnf file:
slow_query_log = 1
long_query_time = 1 (second, or however many seconds you want to have as the minimum slow query duration)
slow_query_log_file = /var/log/mysql/slow_query.log (or where you want the slo query log file to live).
Is it possible that Ansible is  removing the slow query log daily?
Avatar of Faith Victory

ASKER

Yes, everything you mentioned is set in my.cnf.
Ansible is the only thing that comes to mind, and could be responsible.
Avatar of arnold
please post show Variables where Variable_name like '%slow%';

This should output your current settings for slow loging ...

if you are using logrotate to control the file size, does the logratate include postrotate to create the file owned by the user with the correct permissions?
@arnold
I pasted infor about the logrotate above with the question.

Slow log settings are correct and same with other servers.
Nothing in the logrotate points at the slow log filename being rotated.

While you might be using logrotate the info on what or when it rotates the slow log what happens.


its using mysqladmin to flush the log. logrotate itself copies the log file to the archive directory before running the 'mysqladmin flush-error-log flush-engine-log flush-general-log flush-slow-log' on the original log.
It sounds like it should work as setup, where does tthe information not show up?

ASKER CERTIFIED SOLUTION
Avatar of Philip Politowicz, Ph.D.
Philip Politowicz, Ph.D.
Flag of United States of America image

Link to home
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
Start Free Trial
@Philip Politowicz, Ph.D.

Is there any logrotate configuration file in /etc/logrotate.d for the mariadb log files?
  ***yes

*** $ cat /etc/logrotate.d
cat: /etc/logrotate.d: Is a directory
*** $ cd /etc/

*** $ ls -larth
-rw-r--r--.   1 root  root    662 Jul 31  2013 logrotate.conf

Is there an archive directory to which logrotate is writing before you run the mysqladmin flush commands?

 ***logrotate itself copies the log file to the archive directory before running the 'mysqladmin flush-error-log flush-engine-log flush-general-log flush-slow-log' on the original log.


Are there any playbook settings in Ansible explicitly doing the logrotation and log flush in mariadb?

*** According to the IT team, Ansible wont be doing anything daily.


If mariadb is not restarting every day, the configuration of the slow log should not change.

***it's a production server, so mariadb is not restarting at all until a schedule maintenance window.


There is something in the log rotation and post-rotate flush that is resetting the log. Is the file /var/log/mysql/slow_query.log there after the daily log rotation?

***yes, the file exist daily and it's not removed.


I-wx- - - - . 1 mysql mysql 64 Dec 21 08:35 263 -> /var/log/mariab/itv-mysql01-slow.log.
Faith,

You posted in your original question that you ran the show Variables, was the slow log on or off?
what is the ownership of the slow log file?
i think it should be owned by mysql:mysql as the likely username under whose rights mariadb is running.
What do you run for the log to start being written again on the mariadb?
The file listing "263 -> /var/log/mariab/itv-mysql01-slow.log" looks like a Linux symbolic link. Symbolic links should probably have permissions (chmod setting) "lrwxrwxrwx", otherwise whatever's trying to access that file may not have the correct permissions to follow the file linking. Also, do you want that link to be named "263"? If so, that's okay, as long as the mariadb daemon knows to write to file "263" in that directory. Also, the link is pointing to a file in "/var/log/mariab/". Is that the actual install directory, or is it "/var/log/mariadb", or "/var/log/mysql"? Are there any files in the directory "/etc/logrotate.d"?
263 is the FD not the file.
This is weird that the file the file system has the same permissions as the other servers.
Double check whether the setting for slow log data collection is merely dynamic or is also part of the my.cnf file?
I.e. when the logrotate rolls the log and issues relevant parameters to the mariadb, it refreshes and rescinds the slow log settings? The other servers have the slow log parameters in the my.cnf and that is why they are not impacted while this server is?
The settings are part of my.cnf and server configuration are standard across all DC.

# MySQL settings
ignore_db_dirs                                   = BACKUP
max_connections                                  = 1000
default_storage_engine                           = InnoDB
transaction-isolation                            = READ-COMMITTED
event_scheduler                                  = ON
slave_sql_verify_checksum                        = NONE
sql_mode                                         = "TRADITIONAL"
wait_timeout                                     = 28800
log_output                                       = "FILE"
log_slow_filter                                  = 'filesort,filesort_on_disk,tmp_table,tmp_table_on_disk'
long_query_time                                  = 5
min_examined_row_limit                           = 0
innodb_flush_log_at_trx_commit                   = 1
skip_name_resolve                                = 1
tmp_table_size                                   = 64M
max_heap_table_size                              = 64M
thread_cache_size                                = 400
thread_pool_size                                 = 64
table_open_cache                                 = 10000
key_buffer_size                                  = 16
join_buffer_size                                 = 128
table_definition_cache                           = 16384
slow_query_log                                   = 1
slow_query_log_file                              = "/var/log/mariadb/itv-mysql01-slow.log"
log_error                                        = "/var/log/mariadb/itv-mysql01-error.log"
the symbolic link, 263 does nothing as it is not referenced as the destination used by the DB server.

The only possible issue I think deals with whether the connection is really flushed port logrotate.
much depends on the process you have whether you can trigger the rotation of the log out of order without causing issues.

logrotate -f /etc/logrotate.conf

to then see whether the mariadb reattaches to the /var/log/mariadb/itv_mysql01-slow.log

Do you compress slow logs?
see whether the prior log continues getting the updates.

 

Have a command section in your logrotate to flush the slow logs:


mysql -uUSER -pPASS -e "FLUSH SLOW LOGS"

Open in new window

OR

/usr/bin/mysqladmin flush-logs

Open in new window


It appears that all the servers were missing the /var/log/mysqldb/archive directory and others haven't got the correct socket configuration in /root/.my.cnf.  Correcting both of these issues resolve the issue.