MariaDB/query performance/externalstorage

== 5.5.30-MariaDB-mariadb1~precise-log (master) ==
 # 14.1s user time, 60ms system time, 28.68M rss, 100.35M vsz
 # Current date: Thu Jun 4 11:18:40 2015
 # Hostname: es1009
 # Files: slow.log
 # Overall: 55.21k total, 20 unique, 6.19 QPS, 0.00x concurrency __________
 # Time range: 2015-06-04 08:46:43 to 11:15:26
 # Attribute total min max avg 95% stddev median
 # ============ ======= ======= ======= ======= ======= ======= =======
 # Exec time 44s 1us 99ms 798us 6ms 2ms 40us
 # Lock time 847ms 0 2ms 15us 54us 36us 0
 # Rows sent 20.74k 0 426 0.38 0.99 7.83 0
 # Rows examine 20.70k 0 426 0.38 0.99 7.83 0
 # Query size 11.67M 14 195.06k 221.67 124.25 2.21k 65.89
 
 # Profile
 # Rank Query ID Response time Calls R/Call V/M Item
 # ==== ================== ============= ===== ====== ===== ===============
 # 1 0xSANITIZED 42.7052 96.9% 12686 0.0034 0.00 SELECT blobs_cluster?
 # 2 0xSANITIZED 0.5627 1.3% 12827 0.0000 0.00 SET
 # 3 0xSANITIZED 0.5452 1.2% 2139 0.0003 0.00 INSERT blobs_cluster?
 # 4 0xSANITIZED 0.1589 0.4% 12564 0.0000 0.00 ADMIN INIT DB
 # 5 0xSANITIZED 0.0459 0.1% 2019 0.0000 0.00 SHOW MASTER STATUS
 # 6 0xSANITIZED 0.0202 0.0% 12804 0.0000 0.00 ADMIN QUIT
 # 7 0xSANITIZED 0.0135 0.0% 10 0.0014 0.00 SHOW VARIABLES
 # 8 0xSANITIZED 0.0090 0.0% 10 0.0009 0.00 SHOW GLOBAL STATUS
 # 9 0xSANITIZED 0.0039 0.0% 4 0.0010 0.00 SELECT INFORMATION_SCHEMA.INNODB_LOCK_WAITS INFORMATION_SCHEMA.INNODB_TRX INFORMATION_SCHEMA.PROCESSLIST
 # 10 0xSANITIZED 0.0039 0.0% 4 0.0010 0.00 SHOW INNODB STATUS
 # 11 0xSANITIZED 0.0031 0.0% 69 0.0000 0.00 SHOW SLAVE STATUS
 # 12 0xSANITIZED 0.0024 0.0% 10 0.0002 0.00 SELECT blobs_cluster?
 # 13 0xSANITIZED 0.0014 0.0% 28 0.0001 0.00 SELECT
 # 14 0xSANITIZED 0.0012 0.0% 7 0.0002 0.00 SELECT heartbeat.heartbeat
 # 15 0xSANITIZED 0.0005 0.0% 10 0.0001 0.00 SELECT
 # 16 0xSANITIZED 0.0004 0.0% 3 0.0001 0.00 SELECT blobs_cluster?
 # 17 0xSANITIZED 0.0003 0.0% 1 0.0003 0.00 SHOW STATUS
 # 18 0xSANITIZED 0.0003 0.0% 5 0.0001 0.00 SELECT
 # 19 0xSANITIZED 0.0002 0.0% 4 0.0001 0.00 SHOW PROCESSLIST
 # 20 0xSANITIZED 0.0002 0.0% 6 0.0000 0.00 SET
 
 # Query 1: 1.42 QPS, 0.00x concurrency, ID 0xSANITIZED at byte 12097671
 # This item is included in the report because it matches --limit.
 # Scores: V/M = 0.00
 # Time range: 2015-06-04 08:46:44 to 11:15:25
 # Attribute pct total min max avg 95% stddev median
 # ============ === ======= ======= ======= ======= ======= ======= =======
 # Count 22 12686
 # Exec time 96 43s 98us 99ms 3ms 8ms 3ms 4ms
 # Lock time 75 636ms 29us 835us 50us 54us 9us 49us
 # Rows sent 59 12.39k 1 1 1 1 0 1
 # Rows examine 59 12.39k 1 1 1 1 0 1
 # Query size 12 1.50M 109 147 124.18 124.25 4.31 124.25
 # String:
 # Databases wikidatawi... (2769/21%), enwiki (2298/18%)... 300 more
 # Hosts
 # Users wikiuser
 # Query_time distribution
 # 1us
 # 10us #
 # 100us ##############################################
 # 1ms ################################################################
 # 10ms #
 # 100ms #
 # 1s
 # 10s+
 # Tables
 # SHOW TABLE STATUS FROM `wikidatawiki` LIKE 'blobs_cluster25'\G
 # SHOW CREATE TABLE `wikidatawiki`.`blobs_cluster25`\G
 # EXPLAIN /*!50100 PARTITIONS*/
 SELECT /* ExternalStoreDB::fetchBlob SANITIZED */ blob_text FROM `blobs_cluster25` WHERE blob_id = '85913556' LIMIT 1\G
 
 # Query 2: 1.44 QPS, 0.00x concurrency, ID 0xSANITIZED at byte 17589305
 # This item is included in the report because it matches --limit.
 # Scores: V/M = 0.00
 # Time range: 2015-06-04 08:46:44 to 11:15:26
 # Attribute pct total min max avg 95% stddev median
 # ============ === ======= ======= ======= ======= ======= ======= =======
 # Count 23 12827
 # Exec time 1 563ms 29us 157us 43us 44us 5us 42us
 # Lock time 0 0 0 0 0 0 0 0
 # Rows sent 0 0 0 0 0 0 0 0
 # Rows examine 0 0 0 0 0 0 0 0
 # Query size 6 826.74k 66 66 66 66 0 66
 # String:
 # Databases wikidatawi... (2820/21%), enwiki (2144/16%)... 304 more
 # Hosts
 # Users wikiuser
 # Query_time distribution
 # 1us
 # 10us ################################################################
 # 100us #
 # 1ms
 # 10ms
 # 100ms
 # 1s
 # 10s+
 SET group_concat_max_len = 262144, `innodb_lock_wait_timeout` = 15\G
 
 # Query 3: 0.24 QPS, 0.00x concurrency, ID 0xSANITIZED at byte 20342005
 # This item is included in the report because it matches --limit.
 # Scores: V/M = 0.00
 # Time range: 2015-06-04 08:46:47 to 11:15:22
 # Attribute pct total min max avg 95% stddev median
 # ============ === ======= ======= ======= ======= ======= ======= =======
 # Count 3 2139
 # Exec time 1 545ms 120us 9ms 254us 515us 409us 167us
 # Lock time 24 207ms 40us 2ms 96us 273us 123us 60us
 # Rows sent 0 0 0 0 0 0 0 0
 # Rows examine 0 0 0 0 0 0 0 0
 # Query size 73 8.55M 103 195.06k 4.09k 18.47k 10.53k 1.04k
 # String:
 # Databases enwiki (352/16%), wikidatawi... (262/12%)... 116 more
 # Hosts
 # Users wikiuser
 # Query_time distribution
 # 1us
 # 10us
 # 100us ################################################################
 # 1ms #
 # 10ms
 # 100ms
 # 1s
 # 10s+
 # Tables
 # SHOW TABLE STATUS FROM `huwikiquote` LIKE 'blobs_cluster25'\G
 # SHOW CREATE TABLE `huwikiquote`.`blobs_cluster25`\G
 INSERT /* ExternalStoreDB::store SANITIZED */ INTO `blobs_cluster25` (blob_id,blob_text) VALUES (NULL,'<blob contents>')\G
 
 # Query 4: 1.41 QPS, 0.00x concurrency, ID 0xSANITIZED at byte 19919781
 # This item is included in the report because it matches --limit.
 # Scores: V/M = 0.00
 # Time range: 2015-06-04 08:46:44 to 11:15:26
 # Attribute pct total min max avg 95% stddev median
 # ============ === ======= ======= ======= ======= ======= ======= =======
 # Count 22 12564
 # Exec time 0 159ms 7us 88us 12us 13us 2us 12us
 # Lock time 0 0 0 0 0 0 0 0
 # Rows sent 0 0 0 0 0 0 0 0
 # Rows examine 0 0 0 0 0 0 0 0
 # Query size 3 368.09k 30 30 30 30 0 30
 # String:
 # Databases wikidatawi... (2810/22%), enwiki (2090/16%)... 287 more
 # Hosts
 # Users wikiuser
 # Query_time distribution
 # 1us #
 # 10us ################################################################
 # 100us
 # 1ms
 # 10ms
 # 100ms
 # 1s
 # 10s+
 administrator command: Init DB\G
 
 # Query 5: 0.23 QPS, 0.00x concurrency, ID 0xSANITIZED at byte 2893029
 # This item is included in the report because it matches --limit.
 # Scores: V/M = 0.00
 # Time range: 2015-06-04 08:46:43 to 11:15:25
 # Attribute pct total min max avg 95% stddev median
 # ============ === ======= ======= ======= ======= ======= ======= =======
 # Count 3 2019
 # Exec time 0 46ms 19us 149us 22us 23us 4us 21us
 # Lock time 0 0 0 0 0 0 0 0
 # Rows sent 0 0 0 0 0 0 0 0
 # Rows examine 0 0 0 0 0 0 0 0
 # Query size 1 120.27k 18 92 61.00 69.19 7.41 59.77
 # String:
 # Databases enwiki (349/17%), wikidatawi... (258/12%)... 102 more
 # Hosts
 # Users wikiuser (1975/97%), watchdog (44/2%)
 # Query_time distribution
 # 1us
 # 10us ################################################################
 # 100us #
 # 1ms
 # 10ms
 # 100ms
 # 1s
 # 10s+
 SHOW /* DatabaseBase::getMasterPos SANITIZED */ MASTER STATUS\G
== 10.0.16-MariaDB-log (slave) ==
 # 37.9s user time, 150ms system time, 32.64M rss, 104.39M vsz
 # Current date: Thu Jun 4 11:19:33 2015
 # Hostname: es1008
 # Files: slow.log
 # Overall: 167.80k total, 10 unique, 19.05 QPS, 0.01x concurrency ________
 # Time range: 2015-06-04 08:48:13 to 11:15:03
 # Attribute total min max avg 95% stddev median
 # ============ ======= ======= ======= ======= ======= ======= =======
 # Exec time 122s 1us 164ms 729us 6ms 2ms 52us
 # Lock time 2s 0 325us 12us 54us 22us 0
 # Rows sent 37.16k 0 22 0.23 0.99 0.43 0
 # Rows examine 36.99k 0 22 0.23 0.99 0.43 0
 # Query size 9.85M 17 362 61.56 124.25 37.32 65.89
 
 # Profile
 # Rank Query ID Response time Calls R/Call V/M Item
 # ==== ================== ============== ===== ====== ===== ==============
 # 1 0xSANITIZED 119.0164 97.2% 37724 0.0032 0.00 SELECT blobs_cluster?
 # 2 0xSANITIZED 2.2171 1.8% 40188 0.0001 0.00 SET
 # 3 0xSANITIZED 0.5836 0.5% 40330 0.0000 0.00 ADMIN INIT DB
 # 4 0xSANITIZED 0.5269 0.4% 8729 0.0001 0.00 SHOW SLAVE STATUS
 # 5 0xSANITIZED 0.0777 0.1% 40549 0.0000 0.00 ADMIN QUIT
 # 6 0xSANITIZED 0.0140 0.0% 20 0.0007 0.00 SELECT blobs_cluster?
 # 7 0xSANITIZED 0.0105 0.0% 165 0.0001 0.00 SELECT
 # 8 0xSANITIZED 0.0062 0.0% 14 0.0004 0.00 SELECT blobs_cluster?
 # 9 0xSANITIZED 0.0025 0.0% 31 0.0001 0.00 SHOW ALL SLAVES
 # 10 0xSANITIZED 0.0017 0.0% 51 0.0000 0.00 SHOW MASTER STATUS
 
 # Query 1: 4.28 QPS, 0.01x concurrency, ID 0xSANITIZED at byte 44095294
 # Scores: V/M = 0.00
 # Time range: 2015-06-04 08:48:13 to 11:15:03
 # Attribute pct total min max avg 95% stddev median
 # ============ === ======= ======= ======= ======= ======= ======= =======
 # Count 22 37724
 # Exec time 97 119s 88us 164ms 3ms 7ms 3ms 3ms
 # Lock time 99 2s 32us 325us 55us 63us 6us 54us
 # Rows sent 99 36.84k 1 1 1 1 0 1
 # Rows examine 99 36.84k 1 1 1 1 0 1
 # Query size 45 4.46M 108 148 124.11 124.25 4.40 124.25
 # String:
 # Databases wikidatawi... (8064/21%), enwiki (6861/18%)... 401 more
 # Hosts
 # Users wikiuser
 # Query_time distribution
 # 1us
 # 10us #
 # 100us ################################################
 # 1ms ################################################################
 # 10ms #
 # 100ms #
 # 1s
 # 10s+
 # Tables
 # SHOW TABLE STATUS FROM `wikidatawiki` LIKE 'blobs_cluster25'\G
 # SHOW CREATE TABLE `wikidatawiki`.`blobs_cluster25`\G
 # EXPLAIN /*!50100 PARTITIONS*/
 SELECT /* ExternalStoreDB::fetchBlob SANITIZED */ blob_text FROM `blobs_cluster25` WHERE blob_id = '107270536' LIMIT 1\G
 
 # Query 2: 4.56 QPS, 0.00x concurrency, ID 0xSANITIZED at byte 27164714
 # Scores: V/M = 0.00
 # Time range: 2015-06-04 08:48:13 to 11:15:03
 # Attribute pct total min max avg 95% stddev median
 # ============ === ======= ======= ======= ======= ======= ======= =======
 # Count 23 40188
 # Exec time 1 2s 34us 306us 55us 57us 5us 52us
 # Lock time 0 0 0 0 0 0 0 0
 # Rows sent 0 0 0 0 0 0 0 0
 # Rows examine 0 0 0 0 0 0 0 0
 # Query size 25 2.53M 66 66 66 66 0 66
 # String:
 # Databases wikidatawi... (8689/21%), enwiki (5456/13%)... 538 more
 # Hosts
 # Users wikiuser
 # Query_time distribution
 # 1us
 # 10us ################################################################
 # 100us #
 # 1ms
 # 10ms
 # 100ms
 # 1s
 # 10s+
 SET group_concat_max_len = 262144, `innodb_lock_wait_timeout` = 15\G
 
 # Query 3: 4.58 QPS, 0.00x concurrency, ID 0xSANITIZED at byte 37603515
 # Scores: V/M = 0.00
 # Time range: 2015-06-04 08:48:13 to 11:15:03
 # Attribute pct total min max avg 95% stddev median
 # ============ === ======= ======= ======= ======= ======= ======= =======
 # Count 24 40330
 # Exec time 0 584ms 7us 265us 14us 17us 3us 13us
 # Lock time 0 0 0 0 0 0 0 0
 # Rows sent 0 0 0 0 0 0 0 0
 # Rows examine 0 0 0 0 0 0 0 0
 # Query size 11 1.15M 30 30 30 30 0 30
 # String:
 # Databases wikidatawi... (8742/21%), enwiki (5537/13%)... 530 more
 # Hosts
 # Users wikiuser
 # Query_time distribution
 # 1us #
 # 10us ################################################################
 # 100us #
 # 1ms
 # 10ms
 # 100ms
 # 1s
 # 10s+
 administrator command: Init DB\G
 
 # Query 4: 0.99 QPS, 0.00x concurrency, ID 0xSANITIZED at byte 43387714
 # Scores: V/M = 0.00
 # Time range: 2015-06-04 08:48:13 to 11:15:03
 # Attribute pct total min max avg 95% stddev median
 # ============ === ======= ======= ======= ======= ======= ======= =======
 # Count 5 8729
 # Exec time 0 527ms 37us 225us 60us 63us 5us 57us
 # Lock time 0 0 0 0 0 0 0 0
 # Rows sent 0 0 0 0 0 0 0 0
 # Rows examine 0 0 0 0 0 0 0 0
 # Query size 6 658.31k 17 97 77.23 76.28 3.78 76.28
 # String:
 # Databases wikidatawi... (1060/12%), enwiki (318/3%)... 496 more
 # Hosts (8717/99%), localhost (12/0%)
 # Users wikiuser (8717/99%), nagios (12/0%)
 # Query_time distribution
 # 1us
 # 10us ################################################################
 # 100us #
 # 1ms
 # 10ms
 # 100ms
 # 1s
 # 10s+
 SHOW /* DatabaseMysqlBase::getLagFromSlaveStatus SANITIZED */ SLAVE STATUS\G
 
 # Query 5: 4.60 QPS, 0.00x concurrency, ID 0xSANITIZED at byte 6338462
 # Scores: V/M = 0.00
 # Time range: 2015-06-04 08:48:13 to 11:15:03
 # Attribute pct total min max avg 95% stddev median
 # ============ === ======= ======= ======= ======= ======= ======= =======
 # Count 24 40549
 # Exec time 0 78ms 1us 112us 1us 1us 0 1us
 # Lock time 0 0 0 0 0 0 0 0
 # Rows sent 0 0 0 0 0 0 0 0
 # Rows examine 0 0 0 0 0 0 0 0
 # Query size 10 1.04M 27 27 27 27 0 27
 # String:
 # Databases wikidatawi... (8666/21%), enwiki (5563/13%)... 531 more
 # Hosts (40533/99%), localhost (16/0%)
 # Users wikiuser (40453/99%), watchdog (80/0%)... 1 more
 # Query_time distribution
 # 1us ################################################################
 # 10us #
 # 100us #
 # 1ms
 # 10ms
 # 100ms
 # 1s
 # 10s+
 administrator command: Quit\G