MariaDB/query performance/coreproduction-20151020

From Wikitech

db1072

# 80.5s user time, 280ms system time, 37.92M rss, 109.40M vsz
# Current date: Tue Oct 20 16:58:18 2015
# Hostname: db1072
# Files: slow.log
# Overall: 401.86k total, 392 unique, 1.19k QPS, 0.24x concurrency _______
# Time range: 2015-10-20 16:49:22 to 16:55:00
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time            80s     1us   718ms   198us   301us     2ms   138us
# Lock time            17s       0     4ms    43us    84us    31us    40us
# Rows sent        566.25k       0   1.36k    1.44    1.96   11.43    0.99
# Rows examine     665.93k       0  14.01k    1.70    3.89   27.05    0.99
# Query size       102.27M      17  29.42k  266.85  511.45  341.31  202.40

# Profile
# Rank Query ID           Response time Calls R/Call V/M   Item
# ==== ================== ============= ===== ====== ===== ===============
#    1 0x292432918989C0B8 19.2854 24.2% 74941 0.0003  0.00 SELECT revision page user
#    2 0x10806A876ECCC9F8 12.6303 15.9% 96826 0.0001  0.00 SELECT page
#    3 0xFF2878F771226A9B  4.0687  5.1% 25934 0.0002  0.00 SELECT page revision
#    4 0x305F18D8941EB073  4.0261  5.1%  6128 0.0007  0.01 SELECT revision page user
#    5 0xFD2F0603A3CAE705  3.2801  4.1% 14268 0.0002  0.00 SELECT page revision
#    6 0x338E17B7702E09AE  2.8383  3.6% 18483 0.0002  0.00 SELECT page_restrictions
#    7 0x3D3565A9CA3DE180  2.5850  3.2% 16872 0.0002  0.00 SELECT page
#    8 0x001DE67B89F362F5  2.3239  2.9%    45 0.0516  0.08 SELECT change_tag revision user
#    9 0xBA14B8AF1E21D52B  1.5142  1.9% 13150 0.0001  0.00 SELECT msg_resource
#   10 0x4CF9D9B76BE929F4  1.4988  1.9%  2248 0.0007  0.00 SELECT page_props
#   11 0x83A2FD11148F7465  1.3796  1.7%  1247 0.0011  0.01 SELECT user_properties
#   12 0x977063FE05BA1F06  1.3338  1.7%  2653 0.0005  0.00 SELECT page page_props
#   13 0x7C1D0C83049D7D32  1.2195  1.5%   284 0.0043  0.01 SELECT text
#   14 0x0ABACC4F38B09BF6  1.1583  1.5%    46 0.0252  0.43 SELECT externallinks
[...]
# Query 1: 221.72 QPS, 0.06x concurrency, ID 0x292432918989C0B8 at byte 77977576
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2015-10-20 16:49:22 to 16:55:00
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         18   74941
# Exec time     24     19s   142us    42ms   257us   348us   261us   236us
# Lock time     31      5s    37us   896us    72us   108us    20us    69us
# Rows sent     12  71.84k       0       1    0.98    0.99    0.13    0.99
# Rows examine  10  71.84k       0       1    0.98    0.99    0.13    0.99
# Query size    36  37.63M     501     610  526.52  537.02    9.63  511.45
# String:
# Databases    enwiki
# Hosts
# Users        wikiuser
# Query_time distribution
#   1us
#  10us
# 100us  ################################################################
#   1ms  #
#  10ms  #
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `enwiki` LIKE 'revision'\G
#    SHOW CREATE TABLE `enwiki`.`revision`\G
#    SHOW TABLE STATUS FROM `enwiki` LIKE 'page'\G
#    SHOW CREATE TABLE `enwiki`.`page`\G
#    SHOW TABLE STATUS FROM `enwiki` LIKE 'user'\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT /* Revision::fetchFromConds [SANITIZED] */  
rev_id,rev_page,rev_text_id,rev_timestamp,rev_comment,rev_user_text,rev_user,rev_minor_edit,rev_deleted,rev_len,rev_parent_id,
rev_sha1,rev_content_format,rev_content_model,page_namespace,page_title,page_id,page_latest,page_is_redirect,page_len,user_name  
FROM `revision` INNER JOIN `page` ON ((page_id = rev_page)) LEFT JOIN `user` ON ((rev_user != 0) AND (user_id = rev_user))  
WHERE page_namespace = '2' AND page_title = '[SANITIZED]/Userboxes/Drama/User_Rome' AND (rev_id=page_latest)  LIMIT 1\G

# Query 2: 286.47 QPS, 0.04x concurrency, ID 0x10806A876ECCC9F8 at byte 117203464
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2015-10-20 16:49:22 to 16:55:00
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         24   96826
# Exec time     15     13s    63us     4ms   130us   185us    37us   119us
# Lock time     23      4s    21us     4ms    41us    66us    19us    38us
# Rows sent     15  89.48k       0       1    0.95    0.99    0.22    0.99
# Rows examine  13  89.48k       0       1    0.95    0.99    0.22    0.99
# Query size    17  18.40M     173     420  199.30  212.52   11.19  192.76
# String:
# Databases    enwiki
# Hosts
# Users        wikiuser
# Query_time distribution
#   1us
#  10us  ############
# 100us  ################################################################
#   1ms  #
#  10ms
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `enwiki` LIKE 'page'\G
#    SHOW CREATE TABLE `enwiki`.`page`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT /* LinkCache::addLinkObj [SANITIZED] */  page_id,page_len,page_is_redirect,page_latest,page_content_model  
FROM `page`   WHERE page_namespace = '828' AND page_title = 'Message_box/configuration'  LIMIT 1\G

# Query 3: 76.73 QPS, 0.01x concurrency, ID 0xFF2878F771226A9B at byte 28856521
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2015-10-20 16:49:22 to 16:55:00
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          6   25934
# Exec time      5      4s    78us     1ms   156us   224us    44us   144us
# Lock time      7      1s    23us   531us    48us    76us    16us    44us
# Rows sent      3  21.87k       0       1    0.86    0.99    0.34    0.99
# Rows examine   3  21.87k       0       1    0.86    0.99    0.34    0.99
# Query size     5   5.98M     222     265  241.64  246.02    7.11  234.30
# String:
# Databases    enwiki
# Hosts
# Users        wikiuser
# Query_time distribution
#   1us
#  10us  ##
# 100us  ################################################################
#   1ms  #
#  10ms
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `enwiki` LIKE 'page'\G
#    SHOW CREATE TABLE `enwiki`.`page`\G
#    SHOW TABLE STATUS FROM `enwiki` LIKE 'revision'\G
#    SHOW CREATE TABLE `enwiki`.`revision`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT /* ResourceLoaderWikiModule::getTitleInfo [SANITIZED] */  page_namespace,page_title,rev_len,rev_sha1  
FROM `page` INNER JOIN `revision` ON ((page_latest=rev_id))  WHERE (page_namespace = '8' AND page_title = 'Gadget-switcher.js')\G

# Query 4: 18.13 QPS, 0.01x concurrency, ID 0x305F18D8941EB073 at byte 84896993
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.01
# Time range: 2015-10-20 16:49:22 to 16:55:00
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          1    6128
# Exec time      5      4s   138us    76ms   656us     4ms     2ms   236us
# Lock time      2   447ms    41us   511us    72us   108us    20us    69us
# Rows sent      1   5.98k       1       1       1       1       0       1
# Rows examine   0   5.98k       1       1       1       1       0       1
# Query size     2   2.80M     474     497  479.88  487.09    7.34  463.90
# String:
# Databases    enwiki
# Hosts
# Users        wikiuser
# Query_time distribution
#   1us
#  10us
# 100us  ################################################################
#   1ms  ####
#  10ms  #
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `enwiki` LIKE 'revision'\G
#    SHOW CREATE TABLE `enwiki`.`revision`\G
#    SHOW TABLE STATUS FROM `enwiki` LIKE 'page'\G
#    SHOW CREATE TABLE `enwiki`.`page`\G
#    SHOW TABLE STATUS FROM `enwiki` LIKE 'user'\G
#    SHOW CREATE TABLE `enwiki`.`user`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT /* Revision::fetchFromConds  */  
rev_id,rev_page,rev_text_id,rev_timestamp,rev_comment,rev_user_text,rev_user,rev_minor_edit,rev_deleted,rev_len,rev_parent_id,
rev_sha1,rev_content_format,rev_content_model,page_namespace,page_title,page_id,page_latest,page_is_redirect,page_len,user_name  
FROM `revision` INNER JOIN `page` ON ((page_id = rev_page)) LEFT JOIN `user` ON ((rev_user != 0) AND (user_id = rev_user))  
WHERE page_id = '2381544' AND rev_id = '583867364'  LIMIT 1\G