Comment 14 for bug 1089333

Hi Nil,

Thanks for sharing the InnoDB status output.

So there are about 4 instances where "evicted without access" > 0:
ovaistariq$ grep "evicted without access" /tmp/bug_test_55-178491676.txt |
cut -d "/" -f 2 | awk '{ if($5 > 0) print $0 }'
s, evicted without access 1.00
s, evicted without access 1.00
s, evicted without access 1.00
s, evicted without access 1.00

Hence the bug is reproducible in 5.5. Agree?

On Wed, Jun 25, 2014 at 3:51 AM, Nilnandan Joshi <
<email address hidden>> wrote:

> Ovais,
>
> I have tested the same case with innodb_read_ahead = none and capture
> innodb status output with script.
>
> nilnandan@nilnandan-Dell-XPS:~$ cat inno_status.sh
> #!/bin/bash
> for i in {1..1810}
> do
> mysql --login-path=local -e "show engine innodb status\G" | grep "evicted
> without access"
> sleep 1
> done
> nilnandan@nilnandan-Dell-XPS:~$
>
> I found few entries where evicted without access > 0
>
> i.e Pages read ahead 0.00/s, evicted without access 1.00/s, Random read
> ahead 0.00/s
>
> attached full output of innodb status script.
>
> nilnandan@nilnandan-Dell-XPS:~$ sysbench --test=oltp
> --oltp-table-size=10000000 --oltp-test-mode=complex --oltp-read-only=on
> --num-threads=6 --max-time=1800 --max-requests=0 --mysql-db=dbtest
> --mysql-user=msandbox --mysql-password=msandbox
> --mysql-socket=/tmp/mysql_sandbox5536.sock run
> sysbench 0.4.12: multi-threaded system evaluation benchmark
>
> No DB drivers specified, using mysql
> Running the test with following options:
> Number of threads: 6
>
> Doing OLTP test.
> Running mixed OLTP test
> Doing read-only test
> Using Special distribution (12 iterations, 1 pct of values are returned
> in 75 pct cases)
> Using "BEGIN" for starting transactions
> Using auto_inc on the id column
> Threads started!
> Time limit exceeded, exiting...
> (last message repeated 5 times)
> Done.
>
> OLTP test statistics:
> queries performed:
> read: 62878424
> write: 0
> other: 8982632
> total: 71861056
> transactions: 4491316 (2495.17 per sec.)
> deadlocks: 0 (0.00 per sec.)
> read/write requests: 62878424 (34932.42 per sec.)
> other operations: 8982632 (4990.35 per sec.)
>
> Test execution summary:
> total time: 1800.0021s
> total number of events: 4491316
> total time taken by event execution: 10773.5022
> per-request statistics:
> min: 1.25ms
> avg: 2.40ms
> max: 44.37ms
> approx. 95 percentile: 3.10ms
>
> Threads fairness:
> events (avg/stddev): 748552.6667/1151.99
> execution time (avg/stddev): 1795.5837/0.03
>
> nilnandan@nilnandan-Dell-XPS:~$
>
>
> ** Attachment added: "bug_test_5.5"
>
> https://bugs.launchpad.net/percona-server/+bug/1089333/+attachment/4138745/+files/bug_test_5.5
>
> ** Changed in: percona-server/5.5
> Status: New => Confirmed
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1089333
>
> Title:
> InnoDB incorrectly reports pages as evicted without access although
> read_ahead is disabled
>
> Status in Percona Server with XtraDB:
> New
> Status in Percona Server 5.1 series:
> New
> Status in Percona Server 5.5 series:
> Confirmed
> Status in Percona Server 5.6 series:
> New
>
> Bug description:
> InnoDB regularly reports pages as being "evicted without access" as
> below:
> Pages read ahead 0.00/s, evicted without access 3.12/s, Random read
> ahead 0.00/s
>
> This happens, although read_ahead is disabled:
> | innodb_random_read_ahead | OFF |
> | innodb_read_ahead | none |
> | innodb_read_ahead_threshold | 56 |
>
> Upon code analysis I found out that the status counter
> buf_pool->stat.n_ra_pages_evicted is only incremented in the function
> call buf_LRU_free_from_common_LRU_list. The relevant part of code is:
>
> buf_LRU_free_from_common_LRU_list(
> ...
>
> accessed = buf_page_is_accessed(bpage);
> freed = buf_LRU_free_block(bpage, TRUE, have_LRU_mutex);
> mutex_exit(block_mutex);
>
> if (freed) {
> /* Keep track of pages that are evicted without
> ever being accessed. This gives us a measure of
> the effectiveness of readahead */
> if (!accessed) {
> ++buf_pool->stat.n_ra_pages_evicted;
> }
> return(TRUE);
> }
>
> So the status counter buf_pool->stat.n_ra_pages_evicted can only
> really be incremented if the access time of the page is not set. While
> if read_ahead is disabled, then a page will always have access time
> set, because it would have been accessed to be read into the buffer
> pool.
>
> Upon discussion with Laurynas there seems to be a discrepancy in how
> access time for a page is set. May be Laurynas can comment further
> here.
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/percona-server/+bug/1089333/+subscriptions
>

--

Ovais Tariq, Senior Consultant, Percona

http://www.percona.com | http://www.mysqlperformanceblog.com
Phone : +1 (888) 401-3401 Ext. 552
24/7 Emergency : +1 888 401 3401 ext 911
Skype : ovaistariq

Training : http://www.percona.com/training/
Support : http://www.percona.com/mysql-support/