Flashcache throws an error on startup when flashcache is not used

[Aurimas Mikalauskas]

It's very confusing to have Percona Server error during startup - it is especially confusing if the server in fact fails to start, while the reason is not actually Flashcache. Here's the flashcache notices during the startup:

Mar 31 17:50:19 localhost mysqld: 110331 17:50:19 [Note] Flashcache bypass: disabled
Mar 31 17:50:19 localhost mysqld: 110331 17:50:19 [Note] Flashcache setup error is : ioctl failed

I think it would be best to suppress these unless flashcache device actually exists. Another way to approach this could be a flag to explicitly enable flashcache in Percona Server though I'm guessing that may break existing flashcache installations after upgrade.

Aurimas

[Yves Trudeau (y-trudeau)]

Hi,
  this is due to the way mysql_data_home is set in init_cachedev. I resolved the issue of a customer by adding a "cd $datadir" in the init.d script. Looking at the strace of 5.5.20, I got:

statfs(".", {f_type=0x58465342, f_bsize=4096, f_blocks=67010513, f_bfree=60639395, f_bavail=60639395, f_files=268172992, f_ffree=268172980, f_fsid={2054, 0}, f_namelen=255, f_frsize=4096}) =
 0
open("/etc/mtab", O_RDONLY) = 3
futex(0x318878c020, FUTEX_WAKE_PRIVATE, 2147483647) = 0
fstat(3, {st_mode=S_IFREG|0644, st_size=464, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fd5c33b5000
read(3, "/dev/sda2 / ext4 rw 0 0\nproc /pr"..., 4096) = 464
statfs("/", {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=12901535, f_bfree=11879844, f_bavail=11224484, f_files=3276800, f_ffree=3176908, f_fsid={1141234244, 1206473618}, f_namelen=255
, f_frsize=4096}) = 0
statfs("/proc", {f_type="PROC_SUPER_MAGIC", f_bsize=4096, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0, f_ffree=0, f_fsid={0, 0}, f_namelen=255, f_frsize=4096}) = 0

so the target directory in $bindir which in the case of this customer, is on a different partition. Looking at the same extract from 5.1.60:

statfs("/var/lib/mysql/", {f_type=0x58465342, f_bsize=4096, f_blocks=63446558, f_bfree=63175977, f_bavail=63175977, f_files=253910208, f_ffree=253910131, f_fsid={64768, 0}, f_namelen=255, f_
frsize=4096}) = 0
open("/etc/mtab", O_RDONLY) = 3
futex(0x365c18c020, FUTEX_WAKE_PRIVATE, 2147483647) = 0
fstat(3, {st_mode=S_IFREG|0644, st_size=464, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f07718dd000
read(3, "/dev/sda2 / ext4 rw 0 0\nproc /pr"..., 4096) = 464
statfs("/", {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=12901535, f_bfree=12156233, f_bavail=11500873, f_files=3276800, f_ffree=3216720, f_fsid={439050054, -1249199248}, f_namelen=255
, f_frsize=4096}) = 0
statfs("/proc", {f_type="PROC_SUPER_MAGIC", f_bsize=4096, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0, f_ffree=0, f_fsid={0, 0}, f_namelen=255, f_frsize=4096}) = 0
statfs("/sys", {f_type="SYSFS_MAGIC", f_bsize=4096, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0, f_ffree=0, f_fsid={0, 0}, f_namelen=255, f_frsize=4096}) = 0

Which now correctly consider /var/lib/mysql.

Yves

[Jervin R (revin)]

It looks like even with Yves' workaround, if you have an SSD device which FlashCache will recognize, it will still try to read it.

statfs("/ssd/msb/msb_5_1_570/data/", {f_type=0x58465342, f_bsize=4096, f_blocks=29290523, f_bfree=26584211, f_bavail=26584211, f_files=117219328, f_ffree=117202929, f_fsid={2113, 0}, f_namelen=255, f_frsize=4096}) = 0
open("/etc/mtab", O_RDONLY) = 3
futex(0x3ed858f020, FUTEX_WAKE_PRIVATE, 2147483647) = 0
fstat(3, {st_mode=S_IFREG|0644, st_size=381, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fea6a153000
read(3, "/dev/md1 / ext4 rw 0 0\nproc /pro"..., 4096) = 381
statfs("/", {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=38703867, f_bfree=36404540, f_bavail=34438499, f_files=9830400, f_ffree=9700231, f_fsid={1685259068, -661529586}, f_namelen=255, f_frsize=4096}) = 0
statfs("/proc", {f_type="PROC_SUPER_MAGIC", f_bsize=4096, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0, f_ffree=0, f_fsid={0, 0}, f_namelen=255, f_frsize=4096}) = 0
statfs("/sys", {f_type="SYSFS_MAGIC", f_bsize=4096, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0, f_ffree=0, f_fsid={0, 0}, f_namelen=255, f_frsize=4096}) = 0
statfs("/dev/pts", {f_type="DEVPTS_SUPER_MAGIC", f_bsize=4096, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0, f_ffree=0, f_fsid={0, 0}, f_namelen=255, f_frsize=4096}) = 0
statfs("/dev/shm", {f_type=0x1021994, f_bsize=4096, f_blocks=2040811, f_bfree=2040670, f_bavail=2040670, f_files=2040811, f_ffree=2040800, f_fsid={0, 0}, f_namelen=255, f_frsize=4096}) = 0
statfs("/boot", {f_type="EXT2_SUPER_MAGIC", f_bsize=1024, f_blocks=507736, f_bfree=395517, f_bavail=369304, f_files=131072, f_ffree=131013, f_fsid={-507482768, 405790572}, f_namelen=255, f_frsize=1024}) = 0
statfs("/wok", {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=200365810, f_bfree=194785174, f_bavail=184607165, f_files=50896896, f_ffree=50838176, f_fsid={1987478334, -418244788}, f_namelen=255, f_frsize=4096}) = 0
statfs("/proc/sys/fs/binfmt_misc", {f_type=0x42494e4d, f_bsize=4096, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0, f_ffree=0, f_fsid={0, 0}, f_namelen=255, f_frsize=4096}) = 0
statfs("/var/lib/nfs/rpc_pipefs", {f_type=0x67596969, f_bsize=4096, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0, f_ffree=0, f_fsid={0, 0}, f_namelen=255, f_frsize=4096}) = 0
statfs("/ssd", {f_type=0x58465342, f_bsize=4096, f_blocks=29290523, f_bfree=26584211, f_bavail=26584211, f_files=117219328, f_ffree=117202929, f_fsid={2113, 0}, f_namelen=255, f_frsize=4096}) = 0
close(3) = 0
munmap(0x7fea6a153000, 4096) = 0
open("/dev/sde1", O_RDONLY) = 3
ioctl(3, 0x4004fecd, 0x7fffa7d85a78) = -1 ENOTTY (Inappropriate ioctl for device)
close(3) = 0
write(2, "120810 20:34:55 [Note] Flashcach"..., 51120810 20:34:55 [Note] Flashcache bypass: disabled
) = 51
write(2, "120810 20:34:55 [Note] Flashcach"..., 65120810 20:34:55 [Note] Flashcache setup error is : ioctl failed

[Jervin R (revin)]

Actually, spoke too soon, if I move the datadir off the SSD drive, FlashCache still checks no matter what. The first one on 5.1.57

statfs("/wok/msb/msb_5_1_570/data/", {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=200365810, f_bfree=194779786, f_bavail=184601777, f_files=50896896, f_ffree=50838080, f_fsid={1987478334, -418244788}, f_namelen=255, f_frsize=4096}) = 0
open("/etc/mtab", O_RDONLY) = 3
futex(0x3ed858f020, FUTEX_WAKE_PRIVATE, 2147483647) = 0
fstat(3, {st_mode=S_IFREG|0644, st_size=337, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fdd6f8b5000
read(3, "/dev/md1 / ext4 rw 0 0\nproc /pro"..., 4096) = 337
statfs("/", {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=38703867, f_bfree=36404561, f_bavail=34438520, f_files=9830400, f_ffree=9700237, f_fsid={1685259068, -661529586}, f_namelen=255, f_frsize=4096}) = 0
statfs("/proc", {f_type="PROC_SUPER_MAGIC", f_bsize=4096, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0, f_ffree=0, f_fsid={0, 0}, f_namelen=255, f_frsize=4096}) = 0
statfs("/sys", {f_type="SYSFS_MAGIC", f_bsize=4096, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0, f_ffree=0, f_fsid={0, 0}, f_namelen=255, f_frsize=4096}) = 0
statfs("/dev/pts", {f_type="DEVPTS_SUPER_MAGIC", f_bsize=4096, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0, f_ffree=0, f_fsid={0, 0}, f_namelen=255, f_frsize=4096}) = 0
statfs("/dev/shm", {f_type=0x1021994, f_bsize=4096, f_blocks=2040811, f_bfree=2040670, f_bavail=2040670, f_files=2040811, f_ffree=2040800, f_fsid={0, 0}, f_namelen=255, f_frsize=4096}) = 0
statfs("/boot", {f_type="EXT2_SUPER_MAGIC", f_bsize=1024, f_blocks=507736, f_bfree=395517, f_bavail=369304, f_files=131072, f_ffree=131013, f_fsid={-507482768, 405790572}, f_namelen=255, f_frsize=1024}) = 0
statfs("/wok", {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=200365810, f_bfree=194779786, f_bavail=184601777, f_files=50896896, f_ffree=50838080, f_fsid={1987478334, -418244788}, f_namelen=255, f_frsize=4096}) = 0
close(3) = 0
munmap(0x7fdd6f8b5000, 4096) = 0
open("/dev/md3", O_RDONLY) = 3
ioctl(3, 0x4004fecd, 0x7fff3ad6f1d8) = -1 EINVAL (Invalid argument)
close(3) = 0
write(2, "120810 21:14:39 [Note] Flashcach"..., 51120810 21:14:39 [Note] Flashcache bypass: disabled
) = 51
write(2, "120810 21:14:39 [Note] Flashcach"..., 65120810 21:14:39 [Note] Flashcache setup error is : ioctl failed

This one on 5.1.63

statfs("/wok/msb/msb_5_1_630/data/", {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=200365810, f_bfree=194702836, f_bavail=184524827, f_files=50896896, f_ffree=50832482, f_fsid={1987478334, -418244788}, f_namelen=255, f_frsize=4096}) = 0
open("/etc/mtab", O_RDONLY) = 3
futex(0x3ed858f020, FUTEX_WAKE_PRIVATE, 2147483647) = 0
fstat(3, {st_mode=S_IFREG|0644, st_size=337, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5aad4c7000
read(3, "/dev/md1 / ext4 rw 0 0\nproc /pro"..., 4096) = 337
statfs("/", {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=38703867, f_bfree=36404559, f_bavail=34438518, f_files=9830400, f_ffree=9700237, f_fsid={1685259068...

[Vadim Tkachenko (vadim-tk)]

I do not know a good reliable way to detect if partition has FlashCache.
So I propose to introduce a variable --flashcache=ON|OFF (OFF default),
and perform all check only if flashcache is ON.

[Raghavendra D Prabhu (raghavendra-prabhu)]

It would also be better to have error information with errno.
Something like http://sprunge.us/QjPA?c

[Paco (francisco-trujillo-hacha)]

Hi

I recently have the same problem with percona 5.5 I have a mysql multi configuration in the server and it was working perfectly until a restart on the machine.

Now when I tried to start one of the two instances:

mysqld multi start 1
mysqld multi start 2

I obtain the next error:

130619 9:25:24 [Note] Flashcache bypass: disabled
130619 9:25:24 [Note] Flashcache setup error is : ioctl failed

[Alexey Kopytov (akopytov)]

Paco,

Based on the error log messages, you appear to be using an old Percona Server version, i.e. older than 5.5.27-29.0 where this bug was fixed.

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-2358