MySQL Bugs: #27594: Can't find file: '.\db1\t1.frm' (errno: 13)

Bug #27594	Can't find file: '.\db1\t1.frm' (errno: 13)
Submitted:	2 Apr 2007 19:04	Modified:	4 Nov 2009 16:25
Reporter:	Shane Bester (Platinum Quality Contributor)	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Locking	Severity:	S3 (Non-critical)
Version:	5.0.40	OS:	Windows (Windows only)
Assigned to:	Konstantin Osipov	CPU Architecture:	Any
Tags:	bfsm_2007_05_03

Description:
Mysql on windows has some strange file-related errors.
These are *not* due to user's permissions in most cases.

Run the testcase.c which effectively does the following in 10 threads:

drop database if exists db1
create database db1
create table db1.t1(c1 varchar(255),c2 date, c3 int,key key1(c1,c2,c3),key key2(c3,c2,c1),key key3(c2))engine=innodb
create table db1.t2(c1 varchar(255),c2 date, c3 int,key key1(c1,c2,c3),key key2(c3,c2,c1),key key3(c2))engine=myisam
insert into db1.t1(c1,c2,c3) values ('?','?',?)

Sure we expect failures from the SQL because when one thread tries to insert, the other thread had already dropped the table.  But, I expect to not see platform-specific errors in the logs:

On Windows:
Version: '5.0.40-debug'  socket: ''  port: 3306  yes
070402 20:55:25 [ERROR] mysqld-debug: Can't find file: '.\db1\t1.frm' (errno: 13)
070402 20:55:27 [ERROR] mysqld-debug: Can't find file: '.\db1\t1.frm' (errno: 13)
070402 20:55:29 [ERROR] mysqld-debug: Can't find file: '.\db1\t1.frm' (errno: 13)
070402 20:55:29 [ERROR] mysqld-debug: Can't find file: '.\db1\t1.frm' (errno: 13)
070402 20:55:30 [ERROR] mysqld-debug: Can't find file: '.\db1\t1.frm' (errno: 13)
070402 20:55:31 [ERROR] mysqld-debug: Can't find file: '.\db1\t1.frm' (errno: 13)
070402 20:55:33 [ERROR] mysqld-debug: Can't find file: '.\db1\t1.frm' (errno: 13)
070402 20:55:33 [ERROR] mysqld-debug: Can't find file: '.\db1\t1.frm' (errno: 13)
070402 20:55:34 [ERROR] mysqld-debug: Can't find file: '.\db1\t1.frm' (errno: 13)
070402 20:55:37 [ERROR] mysqld-debug: Can't find file: '.\db1\t1.frm' (errno: 13)

On Linux:
nothing in error log.

How to repeat:
compile attached testcase and point mysql_real_connect to a windows host.  Watch the error log (or console) for errors.  Point to a linux box, and see no errors.

Suggested fix:
.

testcase.

Attachment: bug27594.c (text/plain), 6.23 KiB.

Debug trace showing the error. Search for "errno: 13" to see which threads failed.

Attachment: 13.log.bz2 (application/octet-stream, text), 490.15 KiB.

The real problem is that the open() system call returns EACCESS on win32 when another thread is running rmdir() system call on the directory that open() runs in.
This is a very narrow window time window that results simply in a wrong error message. 
There are some simple solutions to the problem (like using a system-wide lock), but that would create an unneeded bottleneck. To correctly rectify that problem we would need to implement per-database lock (as it's currently done for tables). But that work exceeds the volume of a bug fix. 
Another work-in-progress that can influence the problem at hand is the task to replace the posix file handling function calls with native ones on Win32.

Georgi... why would another thread run an rmdir() on the directory? Nobody is trying to drop the database.
Either you meant another function call (not rmdir) or you must be mistaken here.

Arjen, this testcase of mine does 'drop database if exists db1'

So I'm happy with the explanation of the cause, and I think
this bug report has served a useful purpose in understanding one
circumstance in which errno 13 can be seen.

This needs to be re-checked against 6.0, where we have a new table locking impl.

Unassigning from my lead until it's re-verified (5.4 or 6.0 trees are good).

Closing since isn't more repeatable on server 5.5.0 built from mysql-next-mr source it is still repeatable on 5.0.

c:\dbs>c:\dbs\5.0\bin\mysqld --defaults-file=c:\dbs\5.0\my.ini --standalone --console
091104 14:13:00  InnoDB: Started; log sequence number 0 5696847
091104 14:13:01 [Note] c:\dbs\5.0\bin\mysqld: ready for connections.
Version: '5.0.88-Win X64'  socket: ''  port: 3500  Source distribution
091104 14:16:16 [ERROR] c:\dbs\5.0\bin\mysqld: Can't find file: '.\db1\t1.frm' (errno: 13)

091104 14:18:53 InnoDB Plugin 1.0.5 started; log sequence number 40595737
091104 14:18:53 [Note] Event Scheduler: Loaded 0 events
091104 14:18:53 [Note] c:\dbs\5.5\bin\mysqld: ready for connections.
Version: '5.5.0-beta-Win X64'  socket: ''  port: 3540  Source distribution

Miguel, please tell where the source code or bzr repository for 5.5 is available.
Thanks

Arjen,

You can test against mysql-6.0 too:

miguel@quetzalli:~/bug$ ./bug27594
running initializations..
pre-generating 16777216 bytes of random data
about to spawn 10 threads
..........
completed spawning new database worker threads
testcase is now running, so watch for error output

c:\dbs>c:\dbs\6.0\bin\mysqld --defaults-file=c:\dbs\6.0\my.ini --standalone --console
091104 22:11:01  InnoDB: Started; log sequence number 0 46409
091104 22:11:01 [Note] Event Scheduler: Loaded 0 events
091104 22:11:01 [Note] c:\dbs\6.0\bin\mysqld: ready for connections.
Version: '6.0.12-alpha-Win X64-log'  socket: ''  port: 3600  Source distribution

mysql 6.0 > show processlist\G
*************************** 1. row ***************************
     Id: 1
   User: root
   Host: localhost:49182
     db: NULL
Command: Query
   Time: 0
  State: NULL
   Info: show processlist
*************************** 2. row ***************************
     Id: 4
   User: miguel
   Host: ::ffff:192.168.0.79:46618
     db: test
Command: Query
   Time: 0
  State: freeing items
   Info: insert into db1.t1(c1,c2,c3) values ('fbmwbseszvwadidvowforyziwctmyxncfqdrlddppgcqwpwxleetzakahtfrfl
*************************** 3. row ***************************
     Id: 5
   User: miguel
   Host: ::ffff:192.168.0.79:46620
     db: test
Command: Query
   Time: 1
  State: freeing items
   Info: insert into db1.t1(c1,c2,c3) values ('llpsizkikcwaztvhwmcbafmtokqnhagghbhmtfktgihxszudmwvxwxylrkfvwo

<cut>

I don't know what is the code which fixed it, I just followed the Kostja instructions to test against these servers.

Hi Miguel... since 6.0 was abandoned, what's the point of having it in 6.0 ?
There are a variety of 6.0-related branches on Launchpad, some even with recent changes. So which should we be looking at?

Please appreciate that outside Sun/MySQL we have no idea what the internal versioning logic is right now, and you also have branches/versions that are not public. So please be very clear, and realistically I would only regard a bug as fixed/closed if there is publically available source code for it. So, it's really important we know where on launchpad a branch is that reflects what you are using.
Thanks

I couldn't repeat against current source server mysql-5.1:

*************************** 10. row ***************************
     Id: 11
   User: miguel
   Host: QUETZALLI:42673
     db: test
Command: Query
   Time: 0
  State: freeing items
   Info: insert into db1.t1(c1,c2,c3) values ('ztxxcbmtlnrxmpijspxcsvdeuuhqjhmbzaiwcosskpgexysetvt
*************************** 11. row ***************************
     Id: 12
   User: miguel
   Host: QUETZALLI:42674
     db: test
Command: Query
   Time: 0
  State: update
   Info: insert into db1.t1(c1,c2,c3) values ('bwbhjuhaliomvtbiyjojofgmdlmyvyiuqtmvjijuyxajauqknxh
11 rows in set (0.00 sec)

mysql 5.1 >

c:\dbs>c:\dbs\5.1\bin\mysqld --defaults-file=c:\dbs\5.1\my.ini --standalone --console
091105 12:27:05 [Note] Plugin 'FEDERATED' is disabled.
091105 12:27:06  InnoDB: Started; log sequence number 0 44243
091105 12:27:06 [Note] Event Scheduler: Loaded 0 events
091105 12:27:06 [Note] c:\dbs\5.1\bin\mysqld: ready for connections.
Version: '5.1.42-Win X64-log'  socket: ''  port: 3510  Source distribution

So the version 5.0 it is the only one I was able to repeat.

Arjen,

https://code.launchpad.net/~mysql/mysql-server/mysql-6.0-codebase is a branch to look at, I think.

Thanks Miguel, so essentially the fix is per 5.1.

Valeriy, why would I want to look at any 6.0 branch, if 6.0 has been abandoned?