Percona Toolkit moved to https://jira.percona.com/projects/PT

pt-online-schema-change slightly different nibble queries

Bug #968596 reported by Baron Schwartz on 2012-03-29

This bug affects 1 person

Affects		Status	Importance	Assigned to	Milestone
	Percona Toolkit moved to https://jira.percona.com/projects/PT	Fix Released	Low	Daniel Nichter

Bug Description

In looking at the query log for the upcoming 2.1 version of pt-online-schema-change, between each nibble I see the following strange pattern of duplicated queries apparently doing the same thing, but not quite (notice the offset/limit):

# Query_time: 0.000415 Lock_time: 0.000035 Rows_sent: 1 Rows_examined: 0
SET timestamp=1333052916;
EXPLAIN SELECT /*!40001 SQL_NO_CACHE */ `actor_id`, `actor_id`, `film_id` FROM `sakila`.`film_actor` FORCE INDEX(`PRIMARY`) WHERE ((`actor_id` > '1') OR (`actor_id` = '1' AND `film_id` >= '1')) ORDER BY `actor_id`, `film_id` LIMIT 100, 2 /*next chunk boundary*/;
# User@Host: msandbox[msandbox] @ localhost [127.0.0.1]
# Query_time: 0.000312 Lock_time: 0.000031 Rows_sent: 2 Rows_examined: 101
SET timestamp=1333052916;
SELECT /*!40001 SQL_NO_CACHE */ `actor_id`, `actor_id`, `film_id` FROM `sakila`.`film_actor` FORCE INDEX(`PRIMARY`) WHERE ((`actor_id` > '1') OR (`actor_id` = '1' AND `film_id` >= '1')) ORDER BY `actor_id`, `film_id` LIMIT 99, 2 /*next chunk boundary*/;

This is with --chunk-size=100 explicitly set:

./pt-online-schema-change --execute --alter 'add baron int' D=sakila,t=film_actor,P=12345 --alter-foreign-keys-method=auto --chunk-size=100

Tags:

Related branches

lp:~percona-toolkit-dev/percona-toolkit/pt-osc-metadata-lock-bug-1113301

Merged into lp:percona-toolkit/2.2 at revision 545

Daniel Nichter: Approve on 2013-03-02

Diff: 7587 lines (+3695/-1178) (has conflicts)

85 files modified

bin/pt-archiver (+111/-15)
bin/pt-config-diff (+110/-13)
bin/pt-deadlock-logger (+110/-13)
bin/pt-duplicate-key-checker (+110/-13)
bin/pt-find (+110/-13)
bin/pt-fk-error-logger (+110/-13)
bin/pt-heartbeat (+110/-13)
bin/pt-index-usage (+110/-13)
bin/pt-kill (+110/-13)
bin/pt-online-schema-change (+593/-634)
bin/pt-query-advisor (+110/-13)
bin/pt-query-digest (+110/-13)
bin/pt-show-grants (+110/-13)
bin/pt-slave-delay (+110/-13)
bin/pt-slave-find (+110/-13)
bin/pt-slave-restart (+110/-13)
bin/pt-table-checksum (+115/-65)
bin/pt-table-sync (+110/-13)
bin/pt-table-usage (+116/-22)
bin/pt-upgrade (+110/-13)
bin/pt-variable-advisor (+110/-13)
bin/pt-visual-explain (+116/-22)
lib/DSNParser.pm (+54/-8)
lib/NibbleIterator.pm (+2/-2)
lib/OptionParser.pm (+40/-39)
sandbox/set-mysql (+23/-0)
t/lib/Cxn.t (+14/-2)
t/lib/DSNParser.t (+11/-5)
t/lib/KeySize.t (+4/-4)
t/lib/NibbleIterator.t (+3/-3)
t/lib/Percona/XtraDB/Cluster-no-PXC.t (+14/-2)
t/lib/Percona/XtraDB/Cluster.t (+14/-2)
t/lib/ReplicaLagWaiter.t (+14/-2)
t/pt-archiver/check_slave_lag.t (+10/-18)
t/pt-fifo-split/pt-fifo-split.t (+85/-12)
t/pt-online-schema-change/alter_active_table.t (+2/-2)
t/pt-online-schema-change/ansi_quotes.t (+3/-2)
t/pt-online-schema-change/basics.t (+1/-1)
t/pt-online-schema-change/bugs.t (+3/-2)
t/pt-online-schema-change/check_alter.t (+3/-2)
t/pt-online-schema-change/metadata_locks.t (+102/-0)
t/pt-online-schema-change/plugin.t (+83/-0)
t/pt-online-schema-change/privs.t (+3/-2)
t/pt-online-schema-change/pxc.t (+3/-5)
t/pt-online-schema-change/rename_columns.t (+3/-2)
t/pt-online-schema-change/samples/plugins/all_hooks.pm (+99/-0)
t/pt-online-schema-change/samples/plugins/block_create_triggers.pm (+46/-0)
t/pt-online-schema-change/samples/plugins/block_swap_tables.pm (+46/-0)
t/pt-online-schema-change/samples/stats-dry-run.txt (+3/-3)
t/pt-online-schema-change/samples/stats-execute-5.5.txt (+4/-4)
t/pt-online-schema-change/samples/stats-execute.txt (+3/-3)
t/pt-online-schema-change/sanity_checks.t (+1/-1)
t/pt-online-schema-change/skip_innodb.t (+1/-1)
t/pt-table-checksum/basics.t (+3/-3)
t/pt-table-checksum/bugs.t (+2/-2)
t/pt-table-checksum/char_chunking.t (+2/-2)
t/pt-table-checksum/chunk_index.t (+7/-7)
t/pt-table-checksum/chunk_size.t (+2/-2)
t/pt-table-checksum/create_replicate_table.t (+2/-2)
t/pt-table-checksum/error_handling.t (+3/-3)
t/pt-table-checksum/filters.t (+2/-2)
t/pt-table-checksum/float_precision.t (+2/-2)
t/pt-table-checksum/fnv_64.t (+2/-2)
t/pt-table-checksum/ignore_columns.t (+2/-2)
t/pt-table-checksum/issue_388.t (+2/-2)
t/pt-table-checksum/issue_47.t (+2/-2)
t/pt-table-checksum/issue_602.t (+2/-2)
t/pt-table-checksum/option_sanity.t (+5/-5)
t/pt-table-checksum/privs.t (+2/-2)
t/pt-table-checksum/progress.t (+2/-2)
t/pt-table-checksum/pxc.t (+2/-2)
t/pt-table-checksum/replication_filters.t (+6/-2)
t/pt-table-checksum/resume.t (+2/-2)
t/pt-table-checksum/run_time.t (+2/-2)
t/pt-table-checksum/skip_innodb.t (+2/-2)
t/pt-table-checksum/standard_options.t (+2/-2)
t/pt-table-checksum/throttle.t (+2/-2)
t/pt-table-sync/basics.t (+3/-3)
t/pt-table-sync/bugs.t (+2/-2)
t/pt-table-sync/filters.t (+2/-2)
t/pt-table-sync/issue_560.t (+1/-1)
t/pt-table-sync/issue_627.t (+1/-1)
t/pt-table-sync/issue_996.t (+1/-1)
t/pt-table-sync/triggers.t (+2/-2)
util/aspell.en.pws (+3/-0)

Revision history for this message

Baron Schwartz (baron-xaprb) wrote on 2012-03-29:

Here is the exact SQL of each nibble:

# User@Host: msandbox[msandbox] @ localhost [127.0.0.1]
# Query_time: 0.000233 Lock_time: 0.000033 Rows_sent: 1 Rows_examined: 0
SET timestamp=1333052916;
EXPLAIN SELECT /*!40001 SQL_NO_CACHE */ `actor_id`, `actor_id`, `film_id` FROM `sakila`.`film_actor` FORCE INDEX(`PRIMARY`) WHERE ((`actor_id` > '198') OR (`actor_id` = '198' AND `film_id` >= '406')) ORDER BY `actor_id`, `film_id` LIMIT 100, 2 /*next chunk boundary*/;
# User@Host: msandbox[msandbox] @ localhost [127.0.0.1]
# Query_time: 0.000260 Lock_time: 0.000030 Rows_sent: 0 Rows_examined: 62
SET timestamp=1333052916;
SELECT /*!40001 SQL_NO_CACHE */ `actor_id`, `actor_id`, `film_id` FROM `sakila`.`film_actor` FORCE INDEX(`PRIMARY`) WHERE ((`actor_id` > '198') OR (`actor_id` = '198' AND `film_id` >= '406')) ORDER BY `actor_id`, `film_id` LIMIT 99, 2 /*next chunk boundary*/;
# User@Host: msandbox[msandbox] @ localhost [127.0.0.1]
# Query_time: 0.000314 Lock_time: 0.000032 Rows_sent: 1 Rows_examined: 0
SET timestamp=1333052916;
EXPLAIN SELECT `actor_id`, `film_id`, `last_update` FROM `sakila`.`film_actor` FORCE INDEX(`PRIMARY`) WHERE ((`actor_id` > '198') OR (`actor_id` = '198' AND `film_id` >= '406')) AND ((`actor_id` < '200') OR (`actor_id` = '200' AND `film_id` <= '993')) /*explain pt-online-schema-change 6398 copy nibble*/;
# User@Host: msandbox[msandbox] @ localhost [127.0.0.1]
# Query_time: 0.001491 Lock_time: 0.000040 Rows_sent: 0 Rows_examined: 62
SET timestamp=1333052916;
INSERT LOW_PRIORITY IGNORE INTO `sakila`.`_film_actor_new` (`actor_id`, `film_id`, `last_update`) SELECT `actor_id`, `film_id`, `last_update` FROM `sakila`.`film_actor` FORCE INDEX(`PRIMARY`) WHERE ((`actor_id` > '198') OR (`actor_id` = '198' AND `film_id` >= '406')) AND ((`actor_id` < '200') OR (`actor_id` = '200' AND `film_id` <= '993')) /*pt-online-schema-change 6398 copy nibble*/;
# User@Host: msandbox[msandbox] @ localhost [127.0.0.1]
# Query_time: 0.000715 Lock_time: 0.000000 Rows_sent: 0 Rows_examined: 0
SET timestamp=1333052916;
SHOW WARNINGS;
# User@Host: msandbox[msandbox] @ localhost [127.0.0.1]
# Query_time: 0.000446 Lock_time: 0.000022 Rows_sent: 1 Rows_examined: 1
SET timestamp=1333052916;
SHOW GLOBAL STATUS LIKE 'Threads_running';
# User@Host: msandbox[msandbox] @ localhost [127.0.0.1]
# Query_time: 0.004201 Lock_time: 0.000002 Rows_sent: 0 Rows_examined: 0

Here is the exact SQL of each nibble:

# User@Host: msandbox[msandbox] @ localhost [127.0.0.1]
# Query_time: 0.000233  Lock_time: 0.000033 Rows_sent: 1  Rows_examined: 0
SET timestamp=1333052916;
EXPLAIN SELECT /*!40001 SQL_NO_CACHE */ `actor_id`, `actor_id`, `film_id` FROM `sakila`.`film_actor` FORCE INDEX(`PRIMARY`) WHERE ((`actor_id` > '198') OR (`actor_id` = '198' AND `film_id` >= '406')) ORDER BY `actor_id`, `film_id` LIMIT 100, 2 /*next chunk boundary*/;
# User@Host: msandbox[msandbox] @ localhost [127.0.0.1]
# Query_time: 0.000260  Lock_time: 0.000030 Rows_sent: 0  Rows_examined: 62
SET timestamp=1333052916;
SELECT /*!40001 SQL_NO_CACHE */ `actor_id`, `actor_id`, `film_id` FROM `sakila`.`film_actor` FORCE INDEX(`PRIMARY`) WHERE ((`actor_id` > '198') OR (`actor_id` = '198' AND `film_id` >= '406')) ORDER BY `actor_id`, `film_id` LIMIT 99, 2 /*next chunk boundary*/;
# User@Host: msandbox[msandbox] @ localhost [127.0.0.1]
# Query_time: 0.000314  Lock_time: 0.000032 Rows_sent: 1  Rows_examined: 0
SET timestamp=1333052916;
EXPLAIN SELECT `actor_id`, `film_id`, `last_update` FROM `sakila`.`film_actor` FORCE INDEX(`PRIMARY`) WHERE ((`actor_id` > '198') OR (`actor_id` = '198' AND `film_id` >= '406')) AND ((`actor_id` < '200') OR (`actor_id` = '200' AND `film_id` <= '993')) /*explain pt-online-schema-change 6398 copy nibble*/;
# User@Host: msandbox[msandbox] @ localhost [127.0.0.1]
# Query_time: 0.001491  Lock_time: 0.000040 Rows_sent: 0  Rows_examined: 62
SET timestamp=1333052916;
INSERT LOW_PRIORITY IGNORE INTO `sakila`.`_film_actor_new` (`actor_id`, `film_id`, `last_update`) SELECT `actor_id`, `film_id`, `last_update` FROM `sakila`.`film_actor` FORCE INDEX(`PRIMARY`) WHERE ((`actor_id` > '198') OR (`actor_id` = '198' AND `film_id` >= '406')) AND ((`actor_id` < '200') OR (`actor_id` = '200' AND `film_id` <= '993')) /*pt-online-schema-change 6398 copy nibble*/;
# User@Host: msandbox[msandbox] @ localhost [127.0.0.1]
# Query_time: 0.000715  Lock_time: 0.000000 Rows_sent: 0  Rows_examined: 0
SET timestamp=1333052916;
SHOW WARNINGS;
# User@Host: msandbox[msandbox] @ localhost [127.0.0.1]
# Query_time: 0.000446  Lock_time: 0.000022 Rows_sent: 1  Rows_examined: 1
SET timestamp=1333052916;
SHOW GLOBAL STATUS LIKE 'Threads_running';
# User@Host: msandbox[msandbox] @ localhost [127.0.0.1]
# Query_time: 0.004201  Lock_time: 0.000002 Rows_sent: 0  Rows_examined: 0

summary:

- pt-online-schema-change duplicate nibble queries
+ pt-online-schema-change slightly different nibble queries

Daniel Nichter (daniel-nichter) on 2012-03-30

Changed in percona-toolkit:
milestone:	2.1.1 → none
assignee:	Daniel Nichter (daniel-nichter) → nobody
importance:	Medium → Undecided
tags:	added: nibbler pt-table-checksum

Revision history for this message

Daniel Nichter (daniel-nichter) wrote on 2012-03-30:

Untargeting because I don't think this causes any negative side-effects, and there's no time left to make it into 2.1.1. But it's worth investigating later.

Revision history for this message

Daniel Nichter (daniel-nichter) wrote on 2013-03-01:

Fixed in the linked branch. This was just superficial: the EXPLAIN used the chunk size, but the actual query used the LIMIT value, which is chunk size - 1. Now the EXPLAIN uses the LIMIT value too.

Changed in percona-toolkit:
assignee:	nobody → Daniel Nichter (daniel-nichter)
importance:	Undecided → Low
status:	Confirmed → In Progress
status:	In Progress → Fix Released

Revision history for this message

Shahriyar Rzayev (rzayev-sehriyar) wrote on 2018-01-24:

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

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.