innodb_extend_slow.patch

   1 # name       : innodb_extend_slow.patch
   2 # introduced : 11 or before
   3 # maintainer : Yasufumi
   4 #
   5 #!!! notice !!!
   6 # Any small change to this file in the main branch
   7 # should be done or reviewed by the maintainer!
   8 --- a/storage/innobase/buf/buf0buf.c
   9 +++ b/storage/innobase/buf/buf0buf.c
  10 @@ -51,6 +51,40 @@
  11  #include "dict0dict.h"
  12  #include "log0recv.h"
  13  #include "page0zip.h"
  14 +#include "trx0trx.h"
  15 +
  16 +/* prototypes for new functions added to ha_innodb.cc */
  17 +trx_t* innobase_get_trx();
  18 +
  19 +inline void _increment_page_get_statistics(buf_block_t* block, trx_t* trx)
  20 +{
  21 +       ulint           block_hash;
  22 +       ulint           block_hash_byte;
  23 +       byte            block_hash_offset;
  24 +
  25 +       ut_ad(block);
  26 +
  27 +       if (!innobase_get_slow_log() || !trx || !trx->take_stats)
  28 +               return;
  29 +
  30 +       if (!trx->distinct_page_access_hash) {
  31 +               trx->distinct_page_access_hash = mem_alloc(DPAH_SIZE);
  32 +               memset(trx->distinct_page_access_hash, 0, DPAH_SIZE);
  33 +       }
  34 +
  35 +       block_hash = ut_hash_ulint((block->page.space << 20) + block->page.space +
  36 +                                       block->page.offset, DPAH_SIZE << 3);
  37 +       block_hash_byte = block_hash >> 3;
  38 +       block_hash_offset = (byte) block_hash & 0x07;
  39 +       if (block_hash_byte >= DPAH_SIZE)
  40 +               fprintf(stderr, "!!! block_hash_byte = %lu  block_hash_offset = %d !!!\n", block_hash_byte, block_hash_offset);
  41 +       if (block_hash_offset > 7)
  42 +               fprintf(stderr, "!!! block_hash_byte = %lu  block_hash_offset = %d !!!\n", block_hash_byte, block_hash_offset);
  43 +       if ((trx->distinct_page_access_hash[block_hash_byte] & ((byte) 0x01 << block_hash_offset)) == 0)
  44 +               trx->distinct_page_access++;
  45 +       trx->distinct_page_access_hash[block_hash_byte] |= (byte) 0x01 << block_hash_offset;
  46 +       return;
  47 +}
  48
  49  /*
  50                 IMPLEMENTATION OF THE BUFFER POOL
  51 @@ -1930,8 +1964,16 @@
  52         mutex_t*        block_mutex;
  53         ibool           must_read;
  54         unsigned        access_time;
  55 +       trx_t*          trx = NULL;
  56 +       ulint           sec;
  57 +       ulint           ms;
  58 +       ib_uint64_t     start_time;
  59 +       ib_uint64_t     finish_time;
  60         buf_pool_t*     buf_pool = buf_pool_get(space, offset);
  61
  62 +       if (innobase_get_slow_log()) {
  63 +               trx = innobase_get_trx();
  64 +       }
  65         buf_pool->stat.n_page_gets++;
  66
  67         for (;;) {
  68 @@ -1949,7 +1991,7 @@
  69                 //buf_pool_mutex_exit(buf_pool);
  70                 rw_lock_s_unlock(&buf_pool->page_hash_latch);
  71
  72 -               buf_read_page(space, zip_size, offset);
  73 +               buf_read_page(space, zip_size, offset, trx);
  74
  75  #if defined UNIV_DEBUG || defined UNIV_BUF_DEBUG
  76                 ut_a(++buf_dbg_counter % 37 || buf_validate());
  77 @@ -2045,6 +2087,13 @@
  78                 /* Let us wait until the read operation
  79                 completes */
  80
  81 +               if (innobase_get_slow_log() && trx && trx->take_stats)
  82 +               {
  83 +                       ut_usectime(&sec, &ms);
  84 +                       start_time = (ib_uint64_t)sec * 1000000 + ms;
  85 +               } else {
  86 +                       start_time = 0;
  87 +               }
  88                 for (;;) {
  89                         enum buf_io_fix io_fix;
  90
  91 @@ -2059,6 +2108,12 @@
  92                                 break;
  93                         }
  94                 }
  95 +               if (innobase_get_slow_log() && trx && trx->take_stats && start_time)
  96 +               {
  97 +                       ut_usectime(&sec, &ms);
  98 +                       finish_time = (ib_uint64_t)sec * 1000000 + ms;
  99 +                       trx->io_reads_wait_timer += (ulint)(finish_time - start_time);
 100 +               }
 101         }
 102
 103  #ifdef UNIV_IBUF_COUNT_DEBUG
 104 @@ -2374,6 +2429,11 @@
 105         ibool           must_read;
 106         ulint           retries = 0;
 107         mutex_t*        block_mutex = NULL;
 108 +       trx_t*          trx = NULL;
 109 +       ulint           sec;
 110 +       ulint           ms;
 111 +       ib_uint64_t     start_time;
 112 +       ib_uint64_t     finish_time;
 113         buf_pool_t*     buf_pool = buf_pool_get(space, offset);
 114
 115         ut_ad(mtr);
 116 @@ -2403,6 +2463,9 @@
 117               || ibuf_page_low(space, zip_size, offset,
 118                                FALSE, file, line, NULL));
 119  #endif
 120 +       if (innobase_get_slow_log()) {
 121 +               trx = innobase_get_trx();
 122 +       }
 123         buf_pool->stat.n_page_gets++;
 124         fold = buf_page_address_fold(space, offset);
 125  loop:
 126 @@ -2473,7 +2536,7 @@
 127                         return(NULL);
 128                 }
 129
 130 -               if (buf_read_page(space, zip_size, offset)) {
 131 +               if (buf_read_page(space, zip_size, offset, trx)) {
 132                         retries = 0;
 133                 } else if (retries < BUF_PAGE_READ_MAX_RETRIES) {
 134                         ++retries;
 135 @@ -2782,6 +2845,13 @@
 136                         /* Let us wait until the read operation
 137                         completes */
 138
 139 +                       if (innobase_get_slow_log() && trx && trx->take_stats)
 140 +                       {
 141 +                               ut_usectime(&sec, &ms);
 142 +                               start_time = (ib_uint64_t)sec * 1000000 + ms;
 143 +                       } else {
 144 +                               start_time = 0;
 145 +                       }
 146                         for (;;) {
 147                                 enum buf_io_fix io_fix;
 148
 149 @@ -2796,6 +2866,12 @@
 150                                         break;
 151                                 }
 152                         }
 153 +                       if (innobase_get_slow_log() && trx && trx->take_stats && start_time)
 154 +                       {
 155 +                               ut_usectime(&sec, &ms);
 156 +                               finish_time = (ib_uint64_t)sec * 1000000 + ms;
 157 +                               trx->io_reads_wait_timer += (ulint)(finish_time - start_time);
 158 +                       }
 159                 }
 160
 161                 fix_type = MTR_MEMO_BUF_FIX;
 162 @@ -2822,13 +2898,17 @@
 163                 read-ahead */
 164
 165                 buf_read_ahead_linear(space, zip_size, offset,
 166 -                                     ibuf_inside(mtr));
 167 +                                     ibuf_inside(mtr), trx);
 168         }
 169
 170  #ifdef UNIV_IBUF_COUNT_DEBUG
 171         ut_a(ibuf_count_get(buf_block_get_space(block),
 172                             buf_block_get_page_no(block)) == 0);
 173  #endif
 174 +       if (innobase_get_slow_log()) {
 175 +               _increment_page_get_statistics(block, trx);
 176 +       }
 177 +
 178         return(block);
 179  }
 180
 181 @@ -2852,6 +2932,7 @@
 182         unsigned        access_time;
 183         ibool           success;
 184         ulint           fix_type;
 185 +       trx_t*          trx = NULL;
 186
 187         ut_ad(block);
 188         ut_ad(mtr);
 189 @@ -2929,6 +3010,10 @@
 190  #if defined UNIV_DEBUG_FILE_ACCESSES || defined UNIV_DEBUG
 191         ut_a(block->page.file_page_was_freed == FALSE);
 192  #endif
 193 +       if (innobase_get_slow_log()) {
 194 +               trx = innobase_get_trx();
 195 +       }
 196 +
 197         if (UNIV_UNLIKELY(!access_time)) {
 198                 /* In the case of a first access, try to apply linear
 199                 read-ahead */
 200 @@ -2936,7 +3021,7 @@
 201                 buf_read_ahead_linear(buf_block_get_space(block),
 202                                       buf_block_get_zip_size(block),
 203                                       buf_block_get_page_no(block),
 204 -                                     ibuf_inside(mtr));
 205 +                                     ibuf_inside(mtr), trx);
 206         }
 207
 208  #ifdef UNIV_IBUF_COUNT_DEBUG
 209 @@ -2946,6 +3031,9 @@
 210         buf_pool = buf_pool_from_block(block);
 211         buf_pool->stat.n_page_gets++;
 212
 213 +       if (innobase_get_slow_log()) {
 214 +               _increment_page_get_statistics(block, trx);
 215 +       }
 216         return(TRUE);
 217  }
 218
 219 @@ -2968,6 +3056,7 @@
 220         buf_pool_t*     buf_pool;
 221         ibool           success;
 222         ulint           fix_type;
 223 +       trx_t*          trx = NULL;
 224
 225         ut_ad(mtr);
 226         ut_ad(mtr->state == MTR_ACTIVE);
 227 @@ -3054,6 +3143,11 @@
 228  #endif
 229         buf_pool->stat.n_page_gets++;
 230
 231 +       if (innobase_get_slow_log()) {
 232 +               trx = innobase_get_trx();
 233 +               _increment_page_get_statistics(block, trx);
 234 +       }
 235 +
 236         return(TRUE);
 237  }
 238
 239 --- a/storage/innobase/buf/buf0rea.c
 240 +++ b/storage/innobase/buf/buf0rea.c
 241 @@ -77,7 +77,8 @@
 242                         treat the tablespace as dropped; this is a timestamp we
 243                         use to stop dangling page reads from a tablespace
 244                         which we have DISCARDed + IMPORTed back */
 245 -       ulint   offset) /*!< in: page number */
 246 +       ulint   offset, /*!< in: page number */
 247 +       trx_t*  trx)
 248  {
 249         buf_page_t*     bpage;
 250         ulint           wake_later;
 251 @@ -179,15 +180,15 @@
 252
 253         thd_wait_begin(NULL, THD_WAIT_DISKIO);
 254         if (zip_size) {
 255 -               *err = fil_io(OS_FILE_READ | wake_later,
 256 +               *err = _fil_io(OS_FILE_READ | wake_later,
 257                               sync, space, zip_size, offset, 0, zip_size,
 258 -                             bpage->zip.data, bpage);
 259 +                             bpage->zip.data, bpage, trx);
 260         } else {
 261                 ut_a(buf_page_get_state(bpage) == BUF_BLOCK_FILE_PAGE);
 262
 263 -               *err = fil_io(OS_FILE_READ | wake_later,
 264 +               *err = _fil_io(OS_FILE_READ | wake_later,
 265                               sync, space, 0, offset, 0, UNIV_PAGE_SIZE,
 266 -                             ((buf_block_t*) bpage)->frame, bpage);
 267 +                             ((buf_block_t*) bpage)->frame, bpage, trx);
 268         }
 269         thd_wait_end(NULL);
 270         ut_a(*err == DB_SUCCESS);
 271 @@ -213,7 +214,8 @@
 272  /*==========*/
 273         ulint   space,  /*!< in: space id */
 274         ulint   zip_size,/*!< in: compressed page size in bytes, or 0 */
 275 -       ulint   offset) /*!< in: page number */
 276 +       ulint   offset, /*!< in: page number */
 277 +       trx_t*  trx)
 278  {
 279         buf_pool_t*     buf_pool = buf_pool_get(space, offset);
 280         ib_int64_t      tablespace_version;
 281 @@ -227,7 +229,7 @@
 282
 283         count = buf_read_page_low(&err, TRUE, BUF_READ_ANY_PAGE, space,
 284                                   zip_size, FALSE,
 285 -                                 tablespace_version, offset);
 286 +                                 tablespace_version, offset, trx);
 287         srv_buf_pool_reads += count;
 288         if (err == DB_TABLESPACE_DELETED) {
 289                 ut_print_timestamp(stderr);
 290 @@ -279,7 +281,8 @@
 291         ulint   space,          /*!< in: space id */
 292         ulint   zip_size,       /*!< in: compressed page size in bytes, or 0 */
 293         ulint   offset,         /*!< in: page number; see NOTE 3 above */
 294 -       ibool   inside_ibuf)    /*!< in: TRUE if we are inside ibuf routine */
 295 +       ibool   inside_ibuf,    /*!< in: TRUE if we are inside ibuf routine */
 296 +       trx_t*  trx)
 297  {
 298         buf_pool_t*     buf_pool = buf_pool_get(space, offset);
 299         ib_int64_t      tablespace_version;
 300 @@ -498,7 +501,7 @@
 301                         count += buf_read_page_low(
 302                                 &err, FALSE,
 303                                 ibuf_mode,
 304 -                               space, zip_size, FALSE, tablespace_version, i);
 305 +                               space, zip_size, FALSE, tablespace_version, i, trx);
 306                         if (err == DB_TABLESPACE_DELETED) {
 307                                 ut_print_timestamp(stderr);
 308                                 fprintf(stderr,
 309 @@ -591,7 +594,7 @@
 310                 buf_read_page_low(&err, sync && (i + 1 == n_stored),
 311                                   BUF_READ_ANY_PAGE, space_ids[i],
 312                                   zip_size, TRUE, space_versions[i],
 313 -                                 page_nos[i]);
 314 +                                 page_nos[i], NULL);
 315
 316                 if (UNIV_UNLIKELY(err == DB_TABLESPACE_DELETED)) {
 317  tablespace_deleted:
 318 @@ -733,12 +736,12 @@
 319                 if ((i + 1 == n_stored) && sync) {
 320                         buf_read_page_low(&err, TRUE, BUF_READ_ANY_PAGE, space,
 321                                           zip_size, TRUE, tablespace_version,
 322 -                                         page_nos[i]);
 323 +                                         page_nos[i], NULL);
 324                 } else {
 325                         buf_read_page_low(&err, FALSE, BUF_READ_ANY_PAGE
 326                                           | OS_AIO_SIMULATED_WAKE_LATER,
 327                                           space, zip_size, TRUE,
 328 -                                         tablespace_version, page_nos[i]);
 329 +                                         tablespace_version, page_nos[i], NULL);
 330                 }
 331         }
 332
 333 --- a/storage/innobase/fil/fil0fil.c
 334 +++ b/storage/innobase/fil/fil0fil.c
 335 @@ -4748,7 +4748,7 @@
 336                                  node->name, node->handle, buf,
 337                                  offset_low, offset_high,
 338                                  page_size * n_pages,
 339 -                                NULL, NULL);
 340 +                                NULL, NULL, NULL);
 341  #endif
 342                 if (success) {
 343                         node->size += n_pages;
 344 @@ -5075,7 +5075,7 @@
 345  i/o on a tablespace which does not exist */
 346  UNIV_INTERN
 347  ulint
 348 -fil_io(
 349 +_fil_io(
 350  /*===*/
 351         ulint   type,           /*!< in: OS_FILE_READ or OS_FILE_WRITE,
 352                                 ORed to OS_FILE_LOG, if a log i/o
 353 @@ -5100,8 +5100,9 @@
 354         void*   buf,            /*!< in/out: buffer where to store read data
 355                                 or from where to write; in aio this must be
 356                                 appropriately aligned */
 357 -       void*   message)        /*!< in: message for aio handler if non-sync
 358 +       void*   message,        /*!< in: message for aio handler if non-sync
 359                                 aio used, else ignored */
 360 +       trx_t*  trx)
 361  {
 362         ulint           mode;
 363         fil_space_t*    space;
 364 @@ -5269,7 +5270,7 @@
 365  #else
 366         /* Queue the aio request */
 367         ret = os_aio(type, mode | wake_later, node->name, node->handle, buf,
 368 -                    offset_low, offset_high, len, node, message);
 369 +                    offset_low, offset_high, len, node, message, trx);
 370  #endif
 371         ut_a(ret);
 372
 373 --- a/storage/innobase/handler/ha_innodb.cc
 374 +++ b/storage/innobase/handler/ha_innodb.cc
 375 @@ -1578,6 +1578,16 @@
 376         trx->check_unique_secondary = !thd_test_options(
 377                 thd, OPTION_RELAXED_UNIQUE_CHECKS);
 378
 379 +#ifdef EXTENDED_SLOWLOG
 380 +       if (thd_log_slow_verbosity(thd) & SLOG_V_INNODB) {
 381 +               trx->take_stats = TRUE;
 382 +       } else {
 383 +               trx->take_stats = FALSE;
 384 +       }
 385 +#else
 386 +       trx->take_stats = FALSE;
 387 +#endif
 388 +
 389         DBUG_VOID_RETURN;
 390  }
 391
 392 @@ -1632,6 +1642,32 @@
 393         return(trx);
 394  }
 395
 396 +/*************************************************************************
 397 +Gets current trx. */
 398 +extern "C"
 399 +trx_t*
 400 +innobase_get_trx()
 401 +{
 402 +       THD *thd=current_thd;
 403 +       if (likely(thd != 0)) {
 404 +               trx_t*& trx = thd_to_trx(thd);
 405 +               return(trx);
 406 +       } else {
 407 +               return(NULL);
 408 +       }
 409 +}
 410 +
 411 +extern "C"
 412 +ibool
 413 +innobase_get_slow_log()
 414 +{
 415 +#ifdef EXTENDED_SLOWLOG
 416 +       return((ibool) thd_opt_slow_log());
 417 +#else
 418 +       return(FALSE);
 419 +#endif
 420 +}
 421 +
 422  /*********************************************************************//**
 423  Note that a transaction has been registered with MySQL.
 424  @return true if transaction is registered with MySQL 2PC coordinator */
 425 @@ -9312,6 +9348,25 @@
 426         statement has ended */
 427
 428         if (trx->n_mysql_tables_in_use == 0) {
 429 +#ifdef EXTENDED_SLOWLOG
 430 +               increment_thd_innodb_stats(thd,
 431 +                                       (unsigned long long) trx->id,
 432 +                                       trx->io_reads,
 433 +                                       trx->io_read,
 434 +                                       trx->io_reads_wait_timer,
 435 +                                       trx->lock_que_wait_timer,
 436 +                                       trx->innodb_que_wait_timer,
 437 +                                       trx->distinct_page_access);
 438 +
 439 +               trx->io_reads = 0;
 440 +               trx->io_read = 0;
 441 +               trx->io_reads_wait_timer = 0;
 442 +               trx->lock_que_wait_timer = 0;
 443 +               trx->innodb_que_wait_timer = 0;
 444 +               trx->distinct_page_access = 0;
 445 +               if (trx->distinct_page_access_hash)
 446 +                       memset(trx->distinct_page_access_hash, 0, DPAH_SIZE);
 447 +#endif
 448
 449                 trx->mysql_n_tables_locked = 0;
 450                 prebuilt->used_in_HANDLER = FALSE;
 451 --- a/storage/innobase/include/buf0rea.h
 452 +++ b/storage/innobase/include/buf0rea.h
 453 @@ -27,6 +27,7 @@
 454  #define buf0rea_h
 455
 456  #include "univ.i"
 457 +#include "trx0types.h"
 458  #include "buf0types.h"
 459
 460  /********************************************************************//**
 461 @@ -41,7 +42,8 @@
 462  /*==========*/
 463         ulint   space,  /*!< in: space id */
 464         ulint   zip_size,/*!< in: compressed page size in bytes, or 0 */
 465 -       ulint   offset);/*!< in: page number */
 466 +       ulint   offset, /*!< in: page number */
 467 +       trx_t*  trx);
 468  /********************************************************************//**
 469  Applies linear read-ahead if in the buf_pool the page is a border page of
 470  a linear read-ahead area and all the pages in the area have been accessed.
 471 @@ -73,7 +75,8 @@
 472         ulint   space,          /*!< in: space id */
 473         ulint   zip_size,       /*!< in: compressed page size in bytes, or 0 */
 474         ulint   offset,         /*!< in: page number; see NOTE 3 above */
 475 -       ibool   inside_ibuf);   /*!< in: TRUE if we are inside ibuf routine */
 476 +       ibool   inside_ibuf,    /*!< in: TRUE if we are inside ibuf routine */
 477 +       trx_t*  trx);
 478  /********************************************************************//**
 479  Issues read requests for pages which the ibuf module wants to read in, in
 480  order to contract the insert buffer tree. Technically, this function is like
 481 --- a/storage/innobase/include/fil0fil.h
 482 +++ b/storage/innobase/include/fil0fil.h
 483 @@ -611,9 +611,12 @@
 484  Reads or writes data. This operation is asynchronous (aio).
 485  @return DB_SUCCESS, or DB_TABLESPACE_DELETED if we are trying to do
 486  i/o on a tablespace which does not exist */
 487 +#define fil_io(type, sync, space_id, zip_size, block_offset, byte_offset, len, buf, message) \
 488 +       _fil_io(type, sync, space_id, zip_size, block_offset, byte_offset, len, buf, message, NULL)
 489 +
 490  UNIV_INTERN
 491  ulint
 492 -fil_io(
 493 +_fil_io(
 494  /*===*/
 495         ulint   type,           /*!< in: OS_FILE_READ or OS_FILE_WRITE,
 496                                 ORed to OS_FILE_LOG, if a log i/o
 497 @@ -638,8 +641,9 @@
 498         void*   buf,            /*!< in/out: buffer where to store read data
 499                                 or from where to write; in aio this must be
 500                                 appropriately aligned */
 501 -       void*   message);       /*!< in: message for aio handler if non-sync
 502 +       void*   message,        /*!< in: message for aio handler if non-sync
 503                                 aio used, else ignored */
 504 +       trx_t*  trx);
 505  /**********************************************************************//**
 506  Waits for an aio operation to complete. This function is used to write the
 507  handler for completed requests. The aio array of pending requests is divided
 508 --- a/storage/innobase/include/os0file.h
 509 +++ b/storage/innobase/include/os0file.h
 510 @@ -36,6 +36,7 @@
 511  #define os0file_h
 512
 513  #include "univ.i"
 514 +#include "trx0types.h"
 515
 516  #ifndef __WIN__
 517  #include <dirent.h>
 518 @@ -277,13 +278,17 @@
 519         pfs_os_file_close_func(file, __FILE__, __LINE__)
 520
 521  # define os_aio(type, mode, name, file, buf, offset, offset_high,      \
 522 -               n, message1, message2)                                  \
 523 +               n, message1, message2, trx)                             \
 524         pfs_os_aio_func(type, mode, name, file, buf, offset,            \
 525 -                       offset_high, n, message1, message2,             \
 526 +                       offset_high, n, message1, message2, trx,        \
 527                         __FILE__, __LINE__)
 528
 529  # define os_file_read(file, buf, offset, offset_high, n)               \
 530 -       pfs_os_file_read_func(file, buf, offset, offset_high, n,        \
 531 +       pfs_os_file_read_func(file, buf, offset, offset_high, n, NULL,  \
 532 +                             __FILE__, __LINE__)
 533 +
 534 +# define os_file_read_trx(file, buf, offset, offset_high, n, trx)      \
 535 +       pfs_os_file_read_func(file, buf, offset, offset_high, n, trx,   \
 536                               __FILE__, __LINE__)
 537
 538  # define os_file_read_no_error_handling(file, buf, offset,             \
 539 @@ -319,12 +324,15 @@
 540  # define os_file_close(file)   os_file_close_func(file)
 541
 542  # define os_aio(type, mode, name, file, buf, offset, offset_high,      \
 543 -              n, message1, message2)                                   \
 544 +              n, message1, message2, trx)                              \
 545         os_aio_func(type, mode, name, file, buf, offset, offset_high, n,\
 546 -                   message1, message2)
 547 +                   message1, message2, trx)
 548
 549  # define os_file_read(file, buf, offset, offset_high, n)               \
 550 -       os_file_read_func(file, buf, offset, offset_high, n)
 551 +       os_file_read_func(file, buf, offset, offset_high, n, NULL)
 552 +
 553 +# define os_file_read_trx(file, buf, offset, offset_high, n, trx)      \
 554 +       os_file_read_func(file, buf, offset, offset_high, n, trx)
 555
 556  # define os_file_read_no_error_handling(file, buf, offset,             \
 557                                        offset_high, n)                  \
 558 @@ -692,6 +700,7 @@
 559         ulint           offset_high,/*!< in: most significant 32 bits of
 560                                 offset */
 561         ulint           n,      /*!< in: number of bytes to read */
 562 +       trx_t*          trx,
 563         const char*     src_file,/*!< in: file name where func invoked */
 564         ulint           src_line);/*!< in: line where the func invoked */
 565
 566 @@ -746,6 +755,7 @@
 567                                 (can be used to identify a completed
 568                                 aio operation); ignored if mode is
 569                                  OS_AIO_SYNC */
 570 +       trx_t*          trx,
 571         const char*     src_file,/*!< in: file name where func invoked */
 572         ulint           src_line);/*!< in: line where the func invoked */
 573  /*******************************************************************//**
 574 @@ -889,7 +899,8 @@
 575                                 offset where to read */
 576         ulint           offset_high,/*!< in: most significant 32 bits of
 577                                 offset */
 578 -       ulint           n);     /*!< in: number of bytes to read */
 579 +       ulint           n,      /*!< in: number of bytes to read */
 580 +       trx_t*          trx);
 581  /*******************************************************************//**
 582  Rewind file to its start, read at most size - 1 bytes from it to str, and
 583  NUL-terminate str. All errors are silently ignored. This function is
 584 @@ -1048,10 +1059,11 @@
 585                                 (can be used to identify a completed
 586                                 aio operation); ignored if mode is
 587                                 OS_AIO_SYNC */
 588 -       void*           message2);/*!< in: message for the aio handler
 589 +       void*           message2,/*!< in: message for the aio handler
 590                                 (can be used to identify a completed
 591                                 aio operation); ignored if mode is
 592                                 OS_AIO_SYNC */
 593 +       trx_t*          trx);
 594  /************************************************************************//**
 595  Wakes up all async i/o threads so that they know to exit themselves in
 596  shutdown. */
 597 --- a/storage/innobase/include/os0file.ic
 598 +++ b/storage/innobase/include/os0file.ic
 599 @@ -229,6 +229,7 @@
 600                                 (can be used to identify a completed
 601                                 aio operation); ignored if mode is
 602                                  OS_AIO_SYNC */
 603 +       trx_t*          trx,
 604         const char*     src_file,/*!< in: file name where func invoked */
 605         ulint           src_line)/*!< in: line where the func invoked */
 606  {
 607 @@ -244,7 +245,7 @@
 608                                    src_file, src_line);
 609
 610         result = os_aio_func(type, mode, name, file, buf, offset, offset_high,
 611 -                            n, message1, message2);
 612 +                            n, message1, message2, trx);
 613
 614         register_pfs_file_io_end(locker, n);
 615
 616 @@ -268,6 +269,7 @@
 617         ulint           offset_high,/*!< in: most significant 32 bits of
 618                                 offset */
 619         ulint           n,      /*!< in: number of bytes to read */
 620 +       trx_t*          trx,
 621         const char*     src_file,/*!< in: file name where func invoked */
 622         ulint           src_line)/*!< in: line where the func invoked */
 623  {
 624 @@ -278,7 +280,7 @@
 625         register_pfs_file_io_begin(&state, locker, file, n, PSI_FILE_READ,
 626                                    src_file, src_line);
 627
 628 -       result = os_file_read_func(file, buf, offset, offset_high, n);
 629 +       result = os_file_read_func(file, buf, offset, offset_high, n, trx);
 630
 631         register_pfs_file_io_end(locker, n);
 632
 633 --- a/storage/innobase/include/srv0srv.h
 634 +++ b/storage/innobase/include/srv0srv.h
 635 @@ -71,6 +71,9 @@
 636  #define SRV_AUTO_EXTEND_INCREMENT      \
 637         (srv_auto_extend_increment * ((1024 * 1024) / UNIV_PAGE_SIZE))
 638
 639 +/* prototypes for new functions added to ha_innodb.cc */
 640 +ibool  innobase_get_slow_log();
 641 +
 642  /* Mutex for locking srv_monitor_file */
 643  extern mutex_t srv_monitor_file_mutex;
 644  /* Temporary file for innodb monitor output */
 645 --- a/storage/innobase/include/trx0trx.h
 646 +++ b/storage/innobase/include/trx0trx.h
 647 @@ -743,6 +743,17 @@
 648         /*------------------------------*/
 649         char detailed_error[256];       /*!< detailed error message for last
 650                                         error, or empty. */
 651 +       /*------------------------------*/
 652 +       ulint           io_reads;
 653 +       ib_uint64_t     io_read;
 654 +       ulint           io_reads_wait_timer;
 655 +       ib_uint64_t     lock_que_wait_ustarted;
 656 +       ulint           lock_que_wait_timer;
 657 +       ulint           innodb_que_wait_timer;
 658 +       ulint           distinct_page_access;
 659 +#define        DPAH_SIZE       8192
 660 +       byte*           distinct_page_access_hash;
 661 +       ibool           take_stats;
 662  };
 663
 664  #define TRX_MAX_N_THREADS      32      /* maximum number of
 665 --- a/storage/innobase/lock/lock0lock.c
 666 +++ b/storage/innobase/lock/lock0lock.c
 667 @@ -1765,6 +1765,8 @@
 668  {
 669         lock_t* lock;
 670         trx_t*  trx;
 671 +       ulint   sec;
 672 +       ulint   ms;
 673
 674         ut_ad(mutex_own(&kernel_mutex));
 675
 676 @@ -1823,6 +1825,10 @@
 677         trx->que_state = TRX_QUE_LOCK_WAIT;
 678         trx->was_chosen_as_deadlock_victim = FALSE;
 679         trx->wait_started = time(NULL);
 680 +       if (innobase_get_slow_log() && trx->take_stats) {
 681 +               ut_usectime(&sec, &ms);
 682 +               trx->lock_que_wait_ustarted = (ib_uint64_t)sec * 1000000 + ms;
 683 +       }
 684
 685         ut_a(que_thr_stop(thr));
 686
 687 @@ -3766,6 +3772,8 @@
 688  {
 689         lock_t* lock;
 690         trx_t*  trx;
 691 +       ulint   sec;
 692 +       ulint   ms;
 693
 694         ut_ad(mutex_own(&kernel_mutex));
 695
 696 @@ -3821,6 +3829,10 @@
 697                 return(DB_SUCCESS);
 698         }
 699
 700 +       if (innobase_get_slow_log() && trx->take_stats) {
 701 +               ut_usectime(&sec, &ms);
 702 +               trx->lock_que_wait_ustarted = (ib_uint64_t)sec * 1000000 + ms;
 703 +       }
 704         trx->que_state = TRX_QUE_LOCK_WAIT;
 705         trx->was_chosen_as_deadlock_victim = FALSE;
 706         trx->wait_started = time(NULL);
 707 --- a/storage/innobase/os/os0file.c
 708 +++ b/storage/innobase/os/os0file.c
 709 @@ -43,6 +43,8 @@
 710  #include "srv0start.h"
 711  #include "fil0fil.h"
 712  #include "buf0buf.h"
 713 +#include "trx0sys.h"
 714 +#include "trx0trx.h"
 715  #include "log0recv.h"
 716  #ifndef UNIV_HOTBACKUP
 717  # include "os0sync.h"
 718 @@ -2213,13 +2215,18 @@
 719         ulint           n,      /*!< in: number of bytes to read */
 720         ulint           offset, /*!< in: least significant 32 bits of file
 721                                 offset from where to read */
 722 -       ulint           offset_high) /*!< in: most significant 32 bits of
 723 +       ulint           offset_high, /*!< in: most significant 32 bits of
 724                                 offset */
 725 +       trx_t*          trx)
 726  {
 727         off_t   offs;
 728  #if defined(HAVE_PREAD) && !defined(HAVE_BROKEN_PREAD)
 729         ssize_t n_bytes;
 730  #endif /* HAVE_PREAD && !HAVE_BROKEN_PREAD */
 731 +       ulint           sec;
 732 +       ulint           ms;
 733 +       ib_uint64_t     start_time;
 734 +       ib_uint64_t     finish_time;
 735
 736         ut_a((offset & 0xFFFFFFFFUL) == offset);
 737
 738 @@ -2240,6 +2247,15 @@
 739
 740         os_n_file_reads++;
 741
 742 +       if (innobase_get_slow_log() && trx && trx->take_stats)
 743 +       {
 744 +               trx->io_reads++;
 745 +               trx->io_read += n;
 746 +               ut_usectime(&sec, &ms);
 747 +               start_time = (ib_uint64_t)sec * 1000000 + ms;
 748 +       } else {
 749 +               start_time = 0;
 750 +       }
 751  #if defined(HAVE_PREAD) && !defined(HAVE_BROKEN_PREAD)
 752         os_mutex_enter(os_file_count_mutex);
 753         os_file_n_pending_preads++;
 754 @@ -2253,6 +2269,13 @@
 755         os_n_pending_reads--;
 756         os_mutex_exit(os_file_count_mutex);
 757
 758 +       if (innobase_get_slow_log() && trx && trx->take_stats && start_time)
 759 +       {
 760 +               ut_usectime(&sec, &ms);
 761 +               finish_time = (ib_uint64_t)sec * 1000000 + ms;
 762 +               trx->io_reads_wait_timer += (ulint)(finish_time - start_time);
 763 +       }
 764 +
 765         return(n_bytes);
 766  #else
 767         {
 768 @@ -2289,6 +2312,13 @@
 769                 os_n_pending_reads--;
 770                 os_mutex_exit(os_file_count_mutex);
 771
 772 +               if (innobase_get_slow_log() && trx && trx->take_stats && start_time)
 773 +               {
 774 +                       ut_usectime(&sec, &ms);
 775 +                       finish_time = (ib_uint64_t)sec * 1000000 + ms;
 776 +                       trx->io_reads_wait_timer += (ulint)(finish_time - start_time);
 777 +               }
 778 +
 779                 return(ret);
 780         }
 781  #endif
 782 @@ -2429,7 +2459,8 @@
 783                                 offset where to read */
 784         ulint           offset_high, /*!< in: most significant 32 bits of
 785                                 offset */
 786 -       ulint           n)      /*!< in: number of bytes to read */
 787 +       ulint           n,      /*!< in: number of bytes to read */
 788 +       trx_t*          trx)
 789  {
 790  #ifdef __WIN__
 791         BOOL            ret;
 792 @@ -2504,7 +2535,7 @@
 793         os_bytes_read_since_printout += n;
 794
 795  try_again:
 796 -       ret = os_file_pread(file, buf, n, offset, offset_high);
 797 +       ret = os_file_pread(file, buf, n, offset, offset_high, trx);
 798
 799         if ((ulint)ret == n) {
 800
 801 @@ -2633,7 +2664,7 @@
 802         os_bytes_read_since_printout += n;
 803
 804  try_again:
 805 -       ret = os_file_pread(file, buf, n, offset, offset_high);
 806 +       ret = os_file_pread(file, buf, n, offset, offset_high, NULL);
 807
 808         if ((ulint)ret == n) {
 809
 810 @@ -4027,10 +4058,11 @@
 811                                 (can be used to identify a completed
 812                                 aio operation); ignored if mode is
 813                                 OS_AIO_SYNC */
 814 -       void*           message2)/*!< in: message for the aio handler
 815 +       void*           message2,/*!< in: message for the aio handler
 816                                 (can be used to identify a completed
 817                                 aio operation); ignored if mode is
 818                                 OS_AIO_SYNC */
 819 +       trx_t*          trx)
 820  {
 821         os_aio_array_t* array;
 822         os_aio_slot_t*  slot;
 823 @@ -4078,7 +4110,7 @@
 824
 825                 if (type == OS_FILE_READ) {
 826                         return(os_file_read_func(file, buf, offset,
 827 -                                           offset_high, n));
 828 +                                           offset_high, n, trx));
 829                 }
 830
 831                 ut_a(type == OS_FILE_WRITE);
 832 @@ -4119,6 +4151,11 @@
 833                 array = NULL; /* Eliminate compiler warning */
 834         }
 835
 836 +       if (trx && type == OS_FILE_READ)
 837 +       {
 838 +               trx->io_reads++;
 839 +               trx->io_read += n;
 840 +       }
 841         slot = os_aio_array_reserve_slot(type, array, message1, message2, file,
 842                                          name, buf, offset, offset_high, n);
 843         if (type == OS_FILE_READ) {
 844 --- a/storage/innobase/srv/srv0srv.c
 845 +++ b/storage/innobase/srv/srv0srv.c
 846 @@ -87,6 +87,9 @@
 847  #include "mysql/plugin.h"
 848  #include "mysql/service_thd_wait.h"
 849
 850 +/* prototypes for new functions added to ha_innodb.cc */
 851 +ibool  innobase_get_slow_log();
 852 +
 853  /* The following counter is incremented whenever there is some user activity
 854  in the server */
 855  UNIV_INTERN ulint      srv_activity_count      = 0;
 856 @@ -1232,6 +1235,10 @@
 857         ibool                   has_slept = FALSE;
 858         srv_conc_slot_t*        slot      = NULL;
 859         ulint                   i;
 860 +       ib_uint64_t             start_time = 0L;
 861 +       ib_uint64_t             finish_time = 0L;
 862 +       ulint                   sec;
 863 +       ulint                   ms;
 864
 865  #ifdef UNIV_SYNC_DEBUG
 866         ut_ad(!sync_thread_levels_nonempty_trx(trx->has_search_latch));
 867 @@ -1312,6 +1319,7 @@
 868                 switches. */
 869                 if (SRV_THREAD_SLEEP_DELAY > 0) {
 870                         os_thread_sleep(SRV_THREAD_SLEEP_DELAY);
 871 +                       trx->innodb_que_wait_timer += SRV_THREAD_SLEEP_DELAY;
 872                 }
 873
 874                 trx->op_info = "";
 875 @@ -1371,6 +1379,14 @@
 876  #ifdef UNIV_SYNC_DEBUG
 877         ut_ad(!sync_thread_levels_nonempty_trx(trx->has_search_latch));
 878  #endif /* UNIV_SYNC_DEBUG */
 879 +
 880 +       if (innobase_get_slow_log() && trx->take_stats) {
 881 +               ut_usectime(&sec, &ms);
 882 +               start_time = (ib_uint64_t)sec * 1000000 + ms;
 883 +       } else {
 884 +               start_time = 0;
 885 +       }
 886 +
 887         trx->op_info = "waiting in InnoDB queue";
 888
 889         thd_wait_begin(trx->mysql_thd, THD_WAIT_USER_LOCK);
 890 @@ -1379,6 +1395,12 @@
 891
 892         trx->op_info = "";
 893
 894 +       if (innobase_get_slow_log() && trx->take_stats && start_time) {
 895 +               ut_usectime(&sec, &ms);
 896 +               finish_time = (ib_uint64_t)sec * 1000000 + ms;
 897 +               trx->innodb_que_wait_timer += (ulint)(finish_time - start_time);
 898 +       }
 899 +
 900         os_fast_mutex_lock(&srv_conc_mutex);
 901
 902         srv_conc_n_waiting_threads--;
 903 --- a/storage/innobase/trx/trx0trx.c
 904 +++ b/storage/innobase/trx/trx0trx.c
 905 @@ -188,6 +188,15 @@
 906         trx->global_read_view = NULL;
 907         trx->read_view = NULL;
 908
 909 +       trx->io_reads = 0;
 910 +       trx->io_read = 0;
 911 +       trx->io_reads_wait_timer = 0;
 912 +       trx->lock_que_wait_timer = 0;
 913 +       trx->innodb_que_wait_timer = 0;
 914 +       trx->distinct_page_access = 0;
 915 +       trx->distinct_page_access_hash = NULL;
 916 +       trx->take_stats = FALSE;
 917 +
 918         /* Set X/Open XA transaction identification to NULL */
 919         memset(&trx->xid, 0, sizeof(trx->xid));
 920         trx->xid.formatID = -1;
 921 @@ -221,6 +230,11 @@
 922
 923         mutex_exit(&kernel_mutex);
 924
 925 +       if (innobase_get_slow_log() && trx->take_stats) {
 926 +               trx->distinct_page_access_hash = mem_alloc(DPAH_SIZE);
 927 +               memset(trx->distinct_page_access_hash, 0, DPAH_SIZE);
 928 +       }
 929 +
 930         return(trx);
 931  }
 932
 933 @@ -406,6 +420,12 @@
 934  /*===============*/
 935         trx_t*  trx)    /*!< in, own: trx object */
 936  {
 937 +       if (trx->distinct_page_access_hash)
 938 +       {
 939 +               mem_free(trx->distinct_page_access_hash);
 940 +               trx->distinct_page_access_hash= NULL;
 941 +       }
 942 +
 943         mutex_enter(&kernel_mutex);
 944
 945         UT_LIST_REMOVE(mysql_trx_list, trx_sys->mysql_trx_list, trx);
 946 @@ -427,6 +447,12 @@
 947  /*====================*/
 948         trx_t*  trx)    /*!< in, own: trx object */
 949  {
 950 +       if (trx->distinct_page_access_hash)
 951 +       {
 952 +               mem_free(trx->distinct_page_access_hash);
 953 +               trx->distinct_page_access_hash= NULL;
 954 +       }
 955 +
 956         mutex_enter(&kernel_mutex);
 957
 958         trx_free(trx);
 959 @@ -1212,6 +1238,9 @@
 960         trx_t*  trx)    /*!< in: transaction */
 961  {
 962         que_thr_t*      thr;
 963 +       ulint           sec;
 964 +       ulint           ms;
 965 +       ib_uint64_t     now;
 966
 967         ut_ad(mutex_own(&kernel_mutex));
 968         ut_ad(trx->que_state == TRX_QUE_LOCK_WAIT);
 969 @@ -1226,6 +1255,11 @@
 970                 thr = UT_LIST_GET_FIRST(trx->wait_thrs);
 971         }
 972
 973 +       if (innobase_get_slow_log() && trx->take_stats) {
 974 +               ut_usectime(&sec, &ms);
 975 +               now = (ib_uint64_t)sec * 1000000 + ms;
 976 +               trx->lock_que_wait_timer += (ulint)(now - trx->lock_que_wait_ustarted);
 977 +       }
 978         trx->que_state = TRX_QUE_RUNNING;
 979  }
 980
 981 @@ -1239,6 +1273,9 @@
 982         trx_t*  trx)    /*!< in: transaction in the TRX_QUE_LOCK_WAIT state */
 983  {
 984         que_thr_t*      thr;
 985 +       ulint           sec;
 986 +       ulint           ms;
 987 +       ib_uint64_t     now;
 988
 989         ut_ad(mutex_own(&kernel_mutex));
 990         ut_ad(trx->que_state == TRX_QUE_LOCK_WAIT);
 991 @@ -1253,6 +1290,11 @@
 992                 thr = UT_LIST_GET_FIRST(trx->wait_thrs);
 993         }
 994
 995 +       if (innobase_get_slow_log() && trx->take_stats) {
 996 +               ut_usectime(&sec, &ms);
 997 +               now = (ib_uint64_t)sec * 1000000 + ms;
 998 +               trx->lock_que_wait_timer += (ulint)(now - trx->lock_que_wait_ustarted);
 999 +       }
1000         trx->que_state = TRX_QUE_RUNNING;
1001  }
1002