running tar completely locks up mysql

Question

I am having a seriously weird issue. If I tar some random directory with many files or a single large file tar -pcvf files.tar /var/log, mysql gets completely locked up and all mysql connections get used up for the time tar is running.

My nginx error.log gets filled up with

2011/04/01 04:29:11 [error] 15089#0: *39023131 recv() failed (104: Connection reset by peer) while reading response header from upstream, client: xxx.xxx.xxx.xxx, server: www.domain.com, request: "GET /some.html HTTP/1.1", upstream: "fastcgi://unix:/var/run/php-fpm.sock:", host: "www.domain.com", referrer: "http://www.domain.com/some-other.html"

I see many Locked connections if i run

SHOW PROCESSLIST;

My server has 4 CPUs with 8 cores (32 cores, 64 threads) and 64GB RAM. It has 6x SSD disks in RAID 10. Top shows 100% cpu on 1 core in use for tar but just after tar finishes, mysql cpu use jumps to over 600% for a second or two.

top - 04:48:29 up 37 days, 14:17,  4 users,  load average: 3.82, 1.37, 0.99
Tasks: 1035 total,   1 running, 1034 sleeping,   0 stopped,   0 zombie
Cpu(s):  3.4%us,  7.4%sy,  0.0%ni, 89.1%id,  0.0%wa,  0.0%hi,  0.1%si,  0.0%st
Mem:  65980076k total, 43154916k used, 22825160k free,   523560k buffers
Swap:  1052248k total,        0k used,  1052248k free, 37479984k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
 9325 mysql     15   0 7624m 2.3g 4700 S 606.3  3.6   6861:35 mysqld

• Mysql version is 5.1.56
• Linux 2.6.18-238.1.1.el5 #1 SMP Tue Jan 4 13:32:19 EST 2011 x86_64 x86_64 x86_64 GNU/Linux
• Mysql has binlog enabled

my.cnf is optimized according to tuning-primer and mysqltuner suggestions and without any warnings. (except for connections maxed out because of tar issue)

[mysqld]
server-id        = 100
datadir          = /var/lib/mysql
port             = 3306
socket           = /var/lib/mysql/mysql.sock
log-error        = /var/log/mysql/mysql.err
log-bin          = /var/log/mysql/mysql-bin
log-bin-index    = /var/log/mysql/mysql-bin.index

expire_logs_days = 2
sync_binlog      = 1

skip-external-locking
skip-innodb

slow_query_log           = 1
slow_query_log_file      = /var/log/mysql/slow_query.log
long_query_time          = 10

max_connections          = 768
key_buffer               = 6G
table_cache              = 15360
read_buffer_size         = 2M
read_rnd_buffer_size     = 2M
sort_buffer_size         = 1M
tmp_table_size           = 128M
max_heap_table_size      = 128M
max_allowed_packet       = 16M
bulk_insert_buffer_size  = 16M
myisam_sort_buffer_size  = 128M
thread_cache_size        = 64
join_buffer_size         = 1M

I've tried some other compression tools like pigz and gzip and everything is normal. pigz is multithreaded so it uses all cores to the maximum. Top shows over 3000% cpu use if i run it and mysql runs without a problem - not a single query or table lock.

Anyway i don't know whether this is tar or mysql issue and how to troubleshoot it. I will appreciate any help. Sorry for my English :)

Thanks!

EDIT:

highest iostat 2 during tar

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0.20    0.00    1.31    7.81    0.00   90.68

Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
sda            1179.00       308.00    452244.00        616     904488
sda1              0.00         0.00         0.00          0          0
sda2           1179.00       308.00    452244.00        616     904488
sda3              0.00         0.00         0.00          0          0

highest top during tar

top - 05:26:07 up 37 days, 14:55,  4 users,  load average: 2.45, 1.70, 1.07
Tasks: 1045 total,   2 running, 1043 sleeping,   0 stopped,   0 zombie
Cpu(s):  0.1%us,  1.7%sy,  0.0%ni, 91.7%id,  6.4%wa,  0.0%hi,  0.1%si,  0.0%st
Mem:  65980076k total, 39148160k used, 26831916k free,   488752k buffers
Swap:  1052248k total,        0k used,  1052248k free, 33484548k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
27604 root      25   0 76192 1072  896 R 99.5  0.0   0:23.94 tar

highest vmstat during tar

procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu------
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 1  5      0 21973424 474068 37700200    0    0     1    19    0    0  1  0 99  0  0

highest slabtop during tar

 Active / Total Objects (% used)    : 9150253 / 12383252 (73.9%)
 Active / Total Slabs (% used)      : 452818 / 453490 (99.9%)
 Active / Total Caches (% used)     : 105 / 149 (70.5%)
 Active / Total Size (% used)       : 1359015.74K / 1709422.53K (79.5%)
 Minimum / Average / Maximum Object : 0.02K / 0.14K / 128.00K

  OBJS ACTIVE  USE OBJ SIZE  SLABS OBJ/SLAB CACHE SIZE NAME
8161880 5170966  63%    0.09K 204047       40    816188K buffer_head
2796624 2795723  99%    0.21K 155368       18    621472K dentry_cache
295320 292658  99%    0.09K   7383       40     29532K journal_head
294665 215031  72%    0.52K  42095        7    168380K radix_tree_node
136800 136770  99%    0.02K    950      144      3800K avtab_node
132192  86357  65%    0.08K   2754       48     11016K selinux_inode_security
127680 119472  93%    0.03K   1140      112      4560K size-32
 74565  69314  92%    0.74K  14913        5     59652K ext3_inode_cache
 64320  40789  63%    0.12K   2144       30      8576K inet_peer_cache
 59972  55193  92%    0.17K   2726       22     10904K vm_area_struct

output for cat /proc/mdstat

Personalities :
unused devices: <none>

output for mount

/dev/sda2 on / type ext3 (rw)
proc on /proc type proc (rw)
sysfs on /sys type sysfs (rw)
devpts on /dev/pts type devpts (rw,gid=5,mode=620)
/dev/sda1 on /boot type ext3 (rw)
tmpfs on /dev/shm type tmpfs (rw)
none on /proc/sys/fs/binfmt_misc type binfmt_misc (rw)

output for df -i

Filesystem            Inodes   IUsed   IFree IUse% Mounted on
/dev/sda2            46497792  144610 46353182    1% /
/dev/sda1              26104      46   26058    1% /boot
tmpfs                8247509       1 8247508    1% /dev/shm

Answer 1

Had the exact same problem. Hardware as below...

• HP DL180-G6 Nearline Server
• 4x 300 GB SAS 15k drives
• 2x 1TB SATA 10k drives
• 2x Xeon 5340 2.53 GHz CPU's (8 cores total)
• 32 GB DDR3 1066 MHz
• HP Storageworks HBA P410 (PCI Express - 1 for all HDD's)
• HP Storageworks HBA P212/Zero (PCI Express - 1 for the external tape drive)
• HP Ultrium LTO 4 external SAS tape drive (800/1600 MB)

When we'd run the daily tape backup with tar -options -source from /mnt/backup -destination to /dev/st0 (tape), it would basically lock up the whole damn computer. The first service to suffer was MySQL, which would be unreachable through the Unix filesystem socket (/var/lib/mysql/mysql.sock), and then processes would crash one by one. Even the terminal (bash prompt) was unuseable, and forget about opening anything from within the gui (Gnome Desktop).

The solution was not to use 'nice', but rather use 'ionice'. It wasn't CPU loading that was the issue but disk loading. The disks and the processors are fast enough, but the backbone (hard disk adapter / PCI-express bus / etc.) just could not keep up.

So, here was the fix...

Old tar backup command:

[root@somewhere]# /bin/tar -clpzvf /dev/st0 /mnt/backup

New tar backup command:

[root@somewhere]# /usr/bin/ionice -c2 -n5 /bin/tar -clpzvf /dev/st0 /mnt/backup

For your reference, here is the manpage for 'iowait' command... it is supported on kernels 2.6.13 and newer: - http://linux.die.net/man/1/ionice - ionice priorities for class 2 systems have 'sane' values between 3 and 5 if you are trying to slow something down without making it take forever. where 3 is moderately slowed down and 5 is very much slowed down.

Effectively doubled the time it takes to run the tape backup (from half an hour, now it is about an hour), but who cares, it is now working as desired.

Answer 2

The problem is contention. The fact that the load level is high confirms this.

The sorta-ok solution would be to run the tar process with nice to lower the priority. That may or may not be enough to get mysql to not choke.

The better solution is to put mysql on to different spindles. I assume by the device names this is all running on one local disk. I would suggest getting another disk and moving mysql to it.

Answer 3

What i/o scheduler are you using? (Use cat /sys/block/sda/queue/scheduler to determine it).

Another problem might be that you are poisoning os disk cache with reading large file and mysql data being displaced with this file. In this case you may try to use some compress/backup tool that supports directio (and bypasses os cache).

Another option is to increase mysql's internal page cache (I believe this is possible only for innodb).

Answer 4

I think the issue is most likely with your disks/filesystem/kernel/bus/drivers, and not with tar or mysql.

The fact that adding heavy compression can be used to work around the problem indicates that the problem is contention somewhere in the I/O, filesystem or locking layers, as the burden that tar can put on the file system is less while the CPU is busy with the compression. Probably leaving enough room for MySQL's I/O needs.

EDIT: Just a thought... Could it be that your disk array is simply "too fast" and the linux kernel is not "tuned" or prepared for that kind of fast responses?

Maybe there is some sysctl tuning that could help reduce the blocking. I know too little about the internals of the linux kernel to give proper advice here, but if you can afford a little experimenting, you could try fiddling (after reading/consulting) with the following:

vm.pagecache
vm.max-readahead
vm.overcommit
vm.overcommit_ratio
vm.max_map_count
kernel.sched_interactive
vm.vfs_cache_pressure

and similar sysctls.

RedHat Magazine has an article about virtual memory in linux that could be a good starting point for analysing the problem.

(end answer section)

I think it's weird that you use less than 8 GB RAM for mysql when you have 64 GB in the server. Does the server have other responsibilities as well? File server, perhaps?

How much data do you put in the tar file when you experience these MySQL hangs?

Wanna share the output of cat /proc/mdstat and mount also? (And df -i if is not too private :-)) It would be interesting to see what file systems you use (some are more CPU-intensive than others, some are less "proven"), and if you have a hardware or software RAID, as well as what HBAs you have.

Assuming 2.6.18-238.1.1.el5 #1 is the official RedHat kernel, have you asked their support about the problem? There may be all sorts of "improvement" patches in this kernel that cause this kind of unexpected behaviour that would not be in the vanilla 2.6.18 kernel.

Kinda sucks having this kind of trouble with such a nice server, doesn't it?

Answer 5

Have you try to exclude the bin-log files and index, or all mysql related logs from the tar ? same issue?

Maybe that "sync_binlog = 1" + tar has some blocking effect ?

Answer 6

I should consider using pmp (poor man's profiler) to trace all system calls done by MySQL process during one of those slowdown periods.

With it, you may discover what's making the process wait for so long that seems hung.

Good luck.

Answer 7

I agree with poisonbit, but I can't upvote yet. So here's my version:

Are you absolutely certain that this happens on arbitrary paths ?? As in, any/all paths that have absolutely nothing to do with /var/log or /var/lib ?? Does this problem occur when you're backing up your home directory or /etc for example ?? I suspect your issue is merely a conflict between MySQL and tar.

There is nothing arbitrary about /var/log and much more so when talking about MySQL with binlog enabled.

tar is an archival command; It stands for 'Tape Archiver'. It is not a compression utility, and as such it's going to have wildly different CPU/Mem/disk usage than any compression utility will. You can see and confirm this when you read the man page.

It's primary intent is to take an internally consistent copy of a file and put it somewhere else. If MySQL freaks out only when tar is running, then it's likely tar is pissing off MySQL, and you should shut down MySQL when running backups on /var/log, or use a different backup utility like, say, mysqldump or mysqlhotcopy. Although if all you're doing is copying the binlogs, then perhaps a simple cp will work better than tar.