Possible bug - Percona 5.1.50 generating large amounts of "Err#2 ENOENT" with partitioned

Hey there,

doing some basic performance analysis of Percona 5.1.50 (64bit, on Solaris 10u9, X86) I ran across something interesting.

While using “truss” I noticed a lot of “stat” calls being made. I looked into it and found that Percona seemed to be doing a “stat” call for non-existent frm files for a partitioned table.

Here are some details, we have a table called “httpvod”, which we partition across 168 partitions. Everything seems to work fine, data gets inserted into the correct partition, etc. But when I perform a “truss” on the mysql process here are some results :

truss -c -p 4339

syscall seconds calls errors
read .046 17609 5688
write .035 6035
open .000 35
close .000 35
unlink .000 15
time .023 14096
stat .120 47880 47880
lseek .000 91
getpid .000 10
fdsync .008 83
fcntl .017 11376
lwp_park .000 202
lwp_unpark .000 202
lstat .000 20
readlink .000 15 15
yield .000 75
pread .002 1210
pwrite .021 932
pollsys .000 93
resolvepath .000 10 5


sys totals: .279 100024 53588
usr time: 14.226
elapsed: 22.230

As you can see the “stat” call gets performed/called at a very high rate, but I couldn’t understand why that was. So now, if I dig deeper into the stat call :

#truss -tstat -p 4339

/34: stat("./iqdialoguecdn/httpvod#P#p0.frm", 0xFFFFFD7FFB9868D0) Err#2 ENOENT
/34: stat("./iqdialoguecdn/httpvod#P#p1.frm", 0xFFFFFD7FFB9868D0) Err#2 ENOENT
/34: stat("./iqdialoguecdn/httpvod#P#p2.frm", 0xFFFFFD7FFB9868D0) Err#2 ENOENT
/34: stat("./iqdialoguecdn/httpvod#P#p3.frm", 0xFFFFFD7FFB9868D0) Err#2 ENOENT
/34: stat("./iqdialoguecdn/httpvod#P#p4.frm", 0xFFFFFD7FFB9868D0) Err#2 ENOENT
/34: stat("./iqdialoguecdn/httpvod#P#p5.frm", 0xFFFFFD7FFB9868D0) Err#2 ENOENT
/34: stat("./iqdialoguecdn/httpvod#P#p6.frm", 0xFFFFFD7FFB9868D0) Err#2 ENOENT
/34: stat("./iqdialoguecdn/httpvod#P#p7.frm", 0xFFFFFD7FFB9868D0) Err#2 ENOENT
/34: stat("./iqdialoguecdn/httpvod#P#p8.frm", 0xFFFFFD7FFB9868D0) Err#2 ENOENT
/34: stat("./iqdialoguecdn/httpvod#P#p9.frm", 0xFFFFFD7FFB9868D0) Err#2 ENOENT
/34: stat("./iqdialoguecdn/httpvod#P#p10.frm", 0xFFFFFD7FFB9868D0) Err#2 ENOENT
/34: stat("./iqdialoguecdn/httpvod#P#p11.frm", 0xFFFFFD7FFB9868D0) Err#2 ENOENT
/34: stat("./iqdialoguecdn/httpvod#P#p12.frm", 0xFFFFFD7FFB9868D0) Err#2 ENOENT
/34: stat("./iqdialoguecdn/httpvod#P#p13.frm", 0xFFFFFD7FFB9868D0) Err#2 ENOENT
/34: stat("./iqdialoguecdn/httpvod#P#p14.frm", 0xFFFFFD7FFB9868D0) Err#2 ENOENT
/34: stat("./iqdialoguecdn/httpvod#P#p15.frm", 0xFFFFFD7FFB9868D0) Err#2 ENOENT

And it does this several hundred times, then stops for a while, then does it again, then stops, etc. It seem cyclic, doing this process every 5-10 seconds or so.

What I can’t figure out is why mysql seems to be looking for an “frm” file on a per partition basis. Like I said, everything seems to work good, but obviously these “stat” calls could become a performance issue in the long run.

Regards,
Gino

We haven’t modified the partitioning code AFAIK, so I would bet this is an upstream bug that you can probably reproduce in Oracle’s MySQL server too, and if so, I’d encourage you to file a bug report upstream.

Thanks Baron, we might just do that.

Regards,
Gino