InnoDB buffer pool dump and load not working as expected

[Ovais Tariq]

PXC version:
Server version: 5.6.15-rel63.0-log 5.6.15-, Percona XtraDB Cluster - binary (GPL), Release: 25.5, Revision 759 wsrep_25.5.r4061, wsrep_25.5.r4061

Before shutdown this is what we had:
+-----------------------------------------+--------------------------------------------------+
| Variable_name | Value |
+-----------------------------------------+--------------------------------------------------+
| Innodb_buffer_pool_pages_free | 8180 |
| Innodb_buffer_pool_pages_total | 13107192 |
+-----------------------------------------+--------------------------------------------------+

After restart this is what we have:
+-----------------------------------------+--------------------------------------------------+
| Variable_name | Value |
+-----------------------------------------+--------------------------------------------------+
| Innodb_buffer_pool_dump_status | not started |
| Innodb_buffer_pool_load_status | Buffer pool(s) load completed at 140410 16:27:46 |
| Innodb_buffer_pool_pages_data | 10832 |
| Innodb_buffer_pool_bytes_data | 177471488 |
| Innodb_buffer_pool_pages_dirty | 5631 |
| Innodb_buffer_pool_bytes_dirty | 92258304 |
| Innodb_buffer_pool_pages_flushed | 201 |
| Innodb_buffer_pool_pages_LRU_flushed | 0 |
| Innodb_buffer_pool_pages_free | 13096360 |
| Innodb_buffer_pool_pages_made_not_young | 0 |
| Innodb_buffer_pool_pages_made_young | 0 |
| Innodb_buffer_pool_pages_misc | 0 |
| Innodb_buffer_pool_pages_old | 4155 |
| Innodb_buffer_pool_pages_total | 13107192 |
| Innodb_buffer_pool_read_ahead_rnd | 0 |
| Innodb_buffer_pool_read_ahead | 0 |
| Innodb_buffer_pool_read_ahead_evicted | 0 |
| Innodb_buffer_pool_read_requests | 365151 |
| Innodb_buffer_pool_reads | 7108 |
| Innodb_buffer_pool_wait_free | 0 |
| Innodb_buffer_pool_write_requests | 65981 |
+-----------------------------------------+--------------------------------------------------+

Relevant entries from error log upon shutdown:
2014-04-10 16:19:27 7672 [Note] InnoDB: Starting shutdown...
2014-04-10 16:19:27 2b431fb5a700 InnoDB: Dumping buffer pool(s) to .//ib_buffer_pool
2014-04-10 16:19:31 2b431fb5a700 InnoDB: Buffer pool(s) dump completed at 140410 16:19:31
2014-04-10 16:20:05 7672 [Note] InnoDB: Shutdown completed; log sequence number 171006813788182

Relevant entries from error log upon startup:
2014-04-10 16:26:06 6632 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.15-rel63.0 started; log sequence number 171006813790929
2014-04-10 16:26:06 2bce97758700 InnoDB: Loading buffer pool(s) from .//ib_buffer_pool
2014-04-10 16:26:06 2bce97758700 InnoDB: Buffer pool(s) load completed at 140410 16:26:06

[Raghavendra D Prabhu (raghavendra-prabhu)]

Is the issue here that of being different Innodb_buffer_pool_pages_free before and after load?

[Ovais Tariq (ovais-tariq)]

The issue is related to BP reload not working as expected as can be seen by looking at the values of the relevant status variables after the restart. Innodb_buffer_pool_load_status reports buffer pool reloaded however the pages wasn't loaded back up, out of more than 13M pages in the BP at shutdown, only 10K were loaded.

[Ovais Tariq (ovais-tariq)]

The BP dump/load process gets affected when wsrep tries to recover the position (uuid:seqno) by doing position recovery, when the current sequence number is not available in grastate.dat file. As during that process, InnoDB is started up to recover position and then shutdown. This affects the dump and load process by causing InnoDB to write a new dump file corresponding to the pages read only during the position recovery process.

[Raghavendra D Prabhu (raghavendra-prabhu)]

Yes, that is indeed the root cause. While buffer pool load is prevented during wsrep-recovery, dump is not, so it dumps a much smaller BP.

Need to check if 5.5 is also affected by this.

[Raghavendra D Prabhu (raghavendra-prabhu)]

Only 5.6 should be affected. In 5.5, the dump/restore thread itself is not started.

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PXC-1665