MySQL Bugs: #44013: dfile I/O size instrumentation missing for MyISAM

Bug #44013	dfile I/O size instrumentation missing for MyISAM
Submitted:	1 Apr 2009 14:10	Modified:	14 Jan 2010 18:02
Reporter:	Kay Roepke	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Performance Schema	Severity:	S1 (Critical)
Version:	mysql-6.0-perf	OS:	Any
Assigned to:	Marc ALFF	CPU Architecture:	Any

Description:
It seems that reads and writes to kfile are instrumented properly, but dfile instrumentation is limited to open calls.

compare events for no_index_tab (dynamic row format, no index) and table foo (fixed format, autoinc primary key):
mysql> select right(event_name,5) as file, source, object_instance_begin, operation, number_of_bytes from events_waits_history_long where event_name = 'wait/io/file/myisam/dfile' or event_name = 'wait/io/file/myisam/kfile' order by event_name;
+-------+----------------+---------------------------------------------------------------+-----------+-----------------+
| file  | source         | object_instance_begin                                         | operation | number_of_bytes |
+-------+----------------+---------------------------------------------------------------+-----------+-----------------+
| dfile | mi_open.c:1374 | ./test/no_index_tab.MYD                                       | open      |            NULL | 
| dfile | mi_open.c:1374 | ./test/foo.MYD                                                | open      |            NULL | 
| kfile | mi_open.c:150  | /Volumes/Storage/tmp/data/6.0-perf/data/test/no_index_tab.MYI | open      |            NULL | 
| kfile | mi_open.c:161  | /Volumes/Storage/tmp/data/6.0-perf/data/test/no_index_tab.MYI | read      |              24 | 
| kfile | mi_open.c:1007 | /Volumes/Storage/tmp/data/6.0-perf/data/test/foo.MYI          | write     |             140 | 
| kfile | mi_open.c:222  | /Volumes/Storage/tmp/data/6.0-perf/data/test/no_index_tab.MYI | read      |             297 | 
| kfile | mi_open.c:1007 | /Volumes/Storage/tmp/data/6.0-perf/data/test/no_index_tab.MYI | write     |             124 | 
| kfile | mi_open.c:1007 | /Volumes/Storage/tmp/data/6.0-perf/data/test/no_index_tab.MYI | write     |             124 | 
| kfile | mi_open.c:1007 | /Volumes/Storage/tmp/data/6.0-perf/data/test/no_index_tab.MYI | write     |             124 | 
| kfile | mi_open.c:150  | /Volumes/Storage/tmp/data/6.0-perf/data/test/foo.MYI          | open      |            NULL | 
| kfile | mi_open.c:161  | /Volumes/Storage/tmp/data/6.0-perf/data/test/foo.MYI          | read      |              24 | 
| kfile | mi_open.c:222  | /Volumes/Storage/tmp/data/6.0-perf/data/test/foo.MYI          | read      |             347 | 
+-------+----------------+---------------------------------------------------------------+-----------+-----------------+
12 rows in set (0.02 sec)

How to repeat:
create table no_index_tab ( a varchar(255), b int ) engine=myisam;

insert into no_index_tab set a = 'foo', b = 1;
insert into no_index_tab set a = 'foo', b = 1;
insert into no_index_tab set a = 'foo', b = 1;

results in:
classdump:test kroepke$ ls -l no_index_tab.*
-rw-rw----  1 kroepke  staff   240 Apr  1 15:40 no_index_tab.MYD
-rw-rw----  1 kroepke  staff  1024 Apr  1 15:40 no_index_tab.MYI
-rw-rw----  1 kroepke  staff  8578 Apr  1 15:37 no_index_tab.frm

no writes to dfile are logged.

table foo from above is:
mysql> desc foo;
+-------+---------+------+-----+---------+----------------+
| Field | Type    | Null | Key | Default | Extra          |
+-------+---------+------+-----+---------+----------------+
| a     | int(11) | NO   | PRI | NULL    | auto_increment | 
| b     | int(11) | YES  |     | NULL    |                | 
+-------+---------+------+-----+---------+----------------+
2 rows in set (0.03 sec)

Suggested fix:
add instrumentation for all dfile operations.

a very rough, initial patch for part of it is below.
at least one problem with it:
should mmap be actually used there is no instrumentation for it. the times we would measure could be very small, otoh we would be picking up the mmap_lock waits which makes more sense for that case.
but still there would be an asymmetry when looking for I/O (reads/writes vs. mutex waits)

=== modified file 'storage/myisam/mi_dynrec.c'
--- storage/myisam/mi_dynrec.c	2009-02-06 01:23:03 +0000
+++ storage/myisam/mi_dynrec.c	2009-04-01 15:01:47 +0000
@@ -160,7 +160,7 @@
   {
     if (info->s->concurrent_insert)
       MYSQL_RWLOCK_UNLOCK(&info->s->mmap_lock);
-    return my_pread(info->dfile, Buffer, Count, offset, MyFlags);
+    return MYSQL_PREAD(info->dfile, Buffer, Count, offset, MyFlags);
   }
 }
 
@@ -170,7 +170,7 @@
 size_t mi_nommap_pread(MI_INFO *info, uchar *Buffer,
                        size_t Count, my_off_t offset, myf MyFlags)
 {
-  return my_pread(info->dfile, Buffer, Count, offset, MyFlags);
+  return MYSQL_PREAD(info->dfile, Buffer, Count, offset, MyFlags);
 }
 
 
@@ -218,7 +218,7 @@
     share->nonmmaped_inserts++;
     if (share->concurrent_insert)
       MYSQL_RWLOCK_UNLOCK(&share->mmap_lock);
-    ret= my_pwrite(info->dfile, Buffer, Count, offset, MyFlags);
+    ret= MYSQL_PWRITE(info->dfile, Buffer, Count, offset, MyFlags);
   }
   if (unlikely(mi_get_physical_logging_state(share)))
     myisam_log_pwrite_physical(MI_LOG_WRITE_BYTES_MYD,
@@ -233,7 +233,7 @@
                       size_t Count, my_off_t offset, myf MyFlags)
 {
   MYISAM_SHARE *share= info->s;
-  uint ret= my_pwrite(info->dfile, Buffer, Count, offset, MyFlags);
+  uint ret= MYSQL_PWRITE(info->dfile, Buffer, Count, offset, MyFlags);
   if (unlikely(mi_get_physical_logging_state(share)))
     myisam_log_pwrite_physical(MI_LOG_WRITE_BYTES_MYD,
                                share, Buffer, Count, offset);
@@ -1894,8 +1894,8 @@
       pointer set to the end of the header after this function.
       my_pread() may leave the file pointer untouched.
     */
-    my_seek(file,filepos,MY_SEEK_SET,MYF(0));
-    if (my_read(file, header, sizeof(info->header),MYF(0)) !=
+    MYSQL_SEEK(file,filepos,MY_SEEK_SET,MYF(0));
+    if (MYSQL_READ(file, header, sizeof(info->header),MYF(0)) !=
 	sizeof(info->header))
       goto err;
   }

Question:
should _mi_cmp_buffer in mi_dynrec.c also be instrumented? technically it is doing my_pread on the dfile.

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/71124

2847 Marc Alff	2009-04-01
      Bug#44013 dfile I/O size instrumentation missing for MyISAM
      
      The file instrumentation for MyISAM was incomplete, causing the performance
      schema to return incomplete results.
      
      Implemented the missing instrumented calls,
      added a test case to verify that file io on the key and data file is as
      expected.

Queued in mysql-6.0-perfschema

Merged in:
- mysql-next-mr (Celosia / 5.5.99-m3)
- mysql-6.0-codebase (6.0.14)

Not in any released version. No changelog entry needed.