openxs@ao756:~/dbs/maria10.2$ ps aux | grep mysqld...I think it's time to summarize most important use cases for lsof utility for MySQL DBAs. I am going to show different cases when it can be useful based on public MySQL bug reports.
openxs 4619 0.0 0.0 4452 804 pts/2 S 17:02 0:00 /bin/sh bin/mysqld_safe --no-defaults --port=3308 --malloc-lib=/usr/lib/x86_64-linux-gnu/libjemalloc.so
openxs 4734 0.5 2.9 876368 115156 pts/2 Sl 17:02 0:00 /home/openxs/dbs/maria10.2/bin/mysqld --no-defaults --basedir=/home/openxs/dbs/maria10.2 --datadir=/home/openxs/dbs/maria10.2/data --plugin-dir=/home/openxs/dbs/maria10.2/lib/plugin --log-error=/home/openxs/dbs/maria10.2/data/ao756.err --pid-file=ao756.pid --port=3308
openxs 5391 0.0 0.0 14652 964 pts/2 S+ 17:05 0:00 grep --color=auto mysqld
openxs@ao756:~/dbs/maria10.2$ lsof -p 4734 | grep mall
mysqld 4734 openxs mem REG 252,2 219776 12058822 /usr/lib/x86_64-linux-gnu/libjemalloc.so.1
As one can read in the manual, lsof "lists on its standard output file information about files opened by processes". In one of the simplest possible calls presented above, we just pass PID of the process after -p option and get list of open files for this process. This includes shared libraries the process uses. By default the following format of the output is used:
openxs@ao756:~/dbs/maria10.2$ lsof -p 4734 | moreMost columns have obvious meaning, so let me concentrate on the few. FD should be numeric file descriptor, and it is for normal files. In this case it is also followed by a letter describing the mode under which the file is open (r for read, w for write and u for update). There may be one more letter describing a type of lock applied to the file. But we can see values without any single digit in the output above, so obviously some special values can be present there, like cwd for current working directory, rtd for root directory, txt for program text (code and data) or mem for memory mapped file, etc.
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAMEmysqld 4734 openxs cwd DIR 252,2 4096 29638597 /home/openxs/dbs/maria10.2/data
mysqld 4734 openxs rtd DIR 252,2 4096 2 /
mysqld 4734 openxs txt REG 252,2 147257671 29514843 /home/openxs/dbs/maria10.2/bin/mysqld
mysqld 4734 openxs mem REG 252,2 31792 1311130 /lib/x86_64-linux-gnu/librt-2.19.so
mysqld 4734 openxs mem REG 252,2 101270905 29241175 /home/openxs/dbs/maria10.2/lib/plugin/ha_rocksdb.so
mysqld 4734 openxs DEL REG 0,11 443265 /[aio]
mysqld 4734 openxs 0r CHR 1,3 0t0 1050 /dev/null
mysqld 4734 openxs 1w REG 252,2 52623 5255961 /home/openxs/dbs/maria10.2/data/.rocksdb/LOG
mysqld 4734 openxs 2w REG 252,2 458880 29647192 /home/openxs/dbs/maria10.2/data/ao756.err
mysqld 4734 openxs 3r DIR 252,2 4096 5255249 /home/openxs/dbs/maria10.2/data/.rocksdb...
mysqld 4734 openxs 451u IPv6 443558 0t0 TCP *:3308 (LISTEN)
mysqld 4734 openxs 452u unix 0x0000000000000000 0t0 443559 /tmp/mysql.sock...mysqld 4734 openxs 470u REG 252,2 0 29756970 /home/openxs/dbs/maria10.2/data/mysql/event.MYD
mysqld 4734 openxs 471u REG 252,2 0 29647195 /home/openxs/dbs/maria10.2/data/multi-master.info
TYPE column is also interesting and may have plenty of values (as there are many types of files in Linux). REG means regular file, DIR is, obviously, a directory. Note also unix for a socket and IPv6 for the TCP port mysqld process listens to.
In SIZE/OFF column for normal files we usually see their size in bytes. Values for offset in file are usually prefixed with 0t if the value is decimal, or 0x if it's hex. NAME is obviously a fully specified file name (with symbolic links resolved). Some more details about the output format are discussed in the following examples.
Another usual way to use lsof is to pass a file name and get details about processes that have it opened, like this:
openxs@ao756:~/dbs/maria10.2$ lsof /tmp/mysql.sockIn this case we see that /home/openxs/dbs/maria10.2 is used as a current working directory by 4 processes. Usually this kind of check is used when we can not unmount some directory, but it may be also useful in context of MySQL when you get error messages that some file is already used by other process. In the first example above I was checking what process could use /tmp/mysql.sock file.
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
mysqld 4734 openxs 452u unix 0x0000000000000000 0t0 443559 /tmp/mysql.sock
openxs@ao756:~/dbs/maria10.2$ lsof /home/openxs/dbs/maria10.2
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
mysqld_sa 4619 openxs cwd DIR 252,2 4096 29235594 /home/openxs/dbs/maria10.2
lsof 14354 openxs cwd DIR 252,2 4096 29235594 /home/openxs/dbs/maria10.2
lsof 14355 openxs cwd DIR 252,2 4096 29235594 /home/openxs/dbs/maria10.2
bash 29244 openxs cwd DIR 252,2 4096 29235594 /home/openxs/dbs/maria10.2
Now, with the above details on basic usage in mind, let's check several recent enough MySQL bug reports that demonstrate typical and more advanced usage of lsof:
- Bug #66237 - "Temporary files created by binary log cache are not purged after transaction commit". My former colleague and mentor from Percona, Miguel Angel Nieto (who recently joined a dark side of MongoDB employees) used lsof to show numerous files with names ML* created and left (until connection is closed) by mysqld process in /tmp directory (tmpdir to be precize) of a server with binary logging enabled, when transaction size was larger that binlog cache size. The bug is fixed in 5.6.17+ and 5.7.2+. It shows us a usual way of creating temporary files by MySQL server:
# lsof -p 6112|grep ML mysqld 6112 root 38u REG 7,0 106594304 18 /tmp/MLjw4ecJ (deleted) mysqld 6112 root 39u REG 7,0 237314310 17 /tmp/MLwdWDGW (deleted)
- Bug #82870 - "mysqld opens too many descriptors for slow query log". This bug (that is still "Verified") was opened by my former colleague Sveta Smirnova (now in Percona). Basically, mysqld opens too many descriptors for slow query log (and general query log) if it is turned ON and OFF while concurrent sessions are running. lsof allowed to see multiple descriptors created for the same file, until eventually open_files_limit is hit.
- Bug #83434 - "Select statement with partition selection against MyISAM table opens all partitions". This bug (later declared a duplicate of older one and, eventually, a documented, even if unexpected, behavior by design) was opened by my colleague from MariaDB Geoff Montee. lsof utility helped to show that all partitions are actually opened by the mysqld process in this case.
- Bug #74145 - "FLUSH LOGS improperly disables the logging if the log file cannot be accessed". This bug (still "Verified") was reported by Jean Weisbuch. Here we can see how lsof was used to find out if slow log is open after FLUSH. The logging has to be disabled, but MySQL continue to lie that it is enabled. I remember many cases when lsof also helped to find out where the error log (file with descriptor 2w) is really located/redirected to.
- Bug #77752 - "bind-address wrongly prefers IPv4 over IPv6". This was not a bug (more like a configuration issue), but see how lsof -i is used by Daniël van Eeden to find out what process listens to a specific port, and does it listen to IPv4 or IPv6 address.
- Bug #87589 - "Documentation incorrectly states that LOAD DATA LOCAL INFILE does not use tmpdir". In this "Verified" bug report Geoff Montee used lsof to show that temporary files are really created in tmpdir, not in /tmp (OS temporary directory). This is how you can find out when MySQL manual lies...
- Bug #77519 - "Reported location of Innodb Merge Temp File is wrong". One more bug from Daniël van Eeden, this time "Verified". By calling lsof +L1 during an online alter table, he demonstrated that two temp files are created in tmpdir instead of in the datadir (as described by the manual), while events_waits_history_long table in performance_schema seems to claim it waited ion temporary file in the datadir. Note that in other his bug report, Bug #76225, fixed since 5.7.9 and 5.8.0, he had also shown ML* binlog cache files created that were not instrumented by performance_schema.
- Bug #75706 - "alter table import tablespace creates a temporary table". This bug report by BJ Quinn is formally still "Verified", but according to my former colleague Przemyslaw Malkowski from Percona in recent 5.6.x and 5.7.x versions lsof does NOT show temporary table created. Time to re-verify this bug maybe, if the decision is made on how to implement this?
- Bug #83717 - "Manual does not explain when ddl_log.log file is deleted and how large it can be". My own bug report where lsof was used to show that the ddl_log.log file remains open even after online ALTER completes. Manual is clear about this now.
- what dynamic libraries are really used by the mysqld process
- where the error log and other logs are really located
- what other process may have some file, port or socket opened that is needed for current MySQL instance
- why you may hit open_files_limit or use all free space in some filesystem unexpectedly
- where all kinds of temporary files are created during specific operations
- how MySQL really works with files, ports and sockets