Slow queries with this plugin


#1

I’m analyzing poor performance of one of my sites and found a slow queries log file of about 30MB for a single day. Upon analyzing it it seems most of hte queries are from rtmedia.

Here is my analyzis, any ideas?

# 300ms user time, 20ms system time, 55.46M rss, 100.63M vsz
# Current date: Tue Nov 11 20:46:06 2014
# Hostname: h2118175.stratoserver.net
# Files: mysql-slow.log.1
# Overall: 251 total, 8 unique, 0.00 QPS, 0.01x concurrency ______________
# Time range: 2014-11-10 00:00:04 to 22:52:45
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time           965s      2s      6s      4s      6s      1s      4s
# Lock time           95ms       0    46ms   379us    98us     3ms    76us
# Rows sent         15.75k       0  12.22k   64.25    0.99  794.30    0.99
# Rows examine      15.75k       0  12.22k   64.26    0.99  794.30    0.99
# Query size         6.36M       6   3.69M  25.95k   34.95 286.13k   33.28

# Profile
# Rank Query ID           Response time  Calls R/Call Apdx V/M   Item
# ==== ================== ============== ===== ====== ==== ===== =========
#    1 0xFEA6E6DD9CA0437D 937.3335 97.1%   242 3.8733 0.31  0.30 SHOW TABLES
# MISC 0xMISC              27.9992  2.9%     9 3.1110   NS   0.0 <7 ITEMS>

# Query 1: 0.01 QPS, 0.03x concurrency, ID 0xFEA6E6DD9CA0437D at byte 6701856
# This item is included in the report because it matches --limit.
# Scores: Apdex = 0.31 [1.0], V/M = 0.30
# Query_time sparkline: |      ^ |
# Time range: 2014-11-10 14:10:29 to 22:52:45
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         96     242
# Exec time     97    937s      2s      6s      4s      6s      1s      4s
# Lock time     19    18ms    35us   136us    75us    93us    15us    76us
# Rows sent      1     164       0       1    0.68    0.99    0.46    0.99
# Rows examine   1     164       0       1    0.68    0.99    0.46    0.99
# Query size     0   8.11k      34      35   34.32   34.95    0.50   33.28
# String:
# Databases    c1kk
# Hosts        localhost
# Users        c1kk
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+
SHOW TABLES LIKE 'kk_rt_rtm_media'\G

#2

1.) Dedicated or VPS or Shared hosting? 2.) Server specs? (CPU/Memory/SSD-or-HDD?) 3.) How many media items in your media library?


#3

99% not a server issue. its my own root server. 16GB of ram. 4GB used… everything tuned. hosting 10 websites with minimalistic traffic… the server is falling asleep…

46 items in media library :smile:


#4

Tasks: 110; 1 running Load average: 0.50 0.69 0.89 Uptime: 328 days(!), 12:04:04


#5

What happens when you hit the media heavy pages with:

What are the page load times?


#6

There is nothing media heavy, its a private forum used by about 10 individuals… the media files are just a few images attached to bbpress.

the most “media heavy” page I could find is this:

Perf. grade 74/100 Requests 94 Load time 767ms Page size 619.9kB

and here is a random forum page with one image:


#7

I wouldnt change a thing. You’ve got a 767ms page load time. That’s fantastic. Enjoy it and move on. :slight_smile:


#8

yes BUT this is with the rt media plugin disabled. with it enabled, sometimes I had a 30 MB mysql slow log file each day!

It might be connected with another plugin or not, so I disabled the plugin and analyzed that 30MB log file and found that rt media plugin seems to fill most of it hence I posted my findings here in my first post.


#9

@ovidiu

I can suggest you to install https://wordpress.org/plugins/query-monitor/ on your site and please check “slow queries” result there. I hope you will find all the queries related to rtMedia-pro and BuddyPress-media with less than 0.0xx seconds. Still if you find any of the query which take more time, kindly share with us.

Just for your information, the attached screenshot is taken from our demo site http://demo.rtcamp.com/rtmedia/.

Thanks,

–Nitun


#10

I’ll try and do that if I’m online late at night so the site can be used during the day although I fail to see why a query check plugin would be more accurate than the mysql slow query log itself?

mysql is setup to log slow queries like this:

slow_query_log = 1
slow_query_log_file = /var/log/mysql/mysql-slow.log
long_query_time = 2   

I can email you the log file if you like?

mysql stats can be seen here: https://foo.dj/munin/stratoserver.net/h2118175.stratoserver.net/index.html#mysql2

Looks like my query above was cut off here it is again:

SET timestamp=1415621429;
SHOW TABLES LIKE 'kk_rt_rtm_media';
# Time: 141110 14:10:31
# User@Host: c1kk[c1kk] @ localhost []  Id: 193775
# Query_time: 3.107833  Lock_time: 0.000076 Rows_sent: 1  Rows_examined: 1

Anyway, I’ll leave it off for now and see if I ever have this kind of problem again.

Btw. I used


#11

@ovidiu

It seems like your server is not well optimized. I just checked our own demo server (its a single core) and below is the output like you provided.

# Query 6: 0.01 QPS, 0.00x concurrency, ID 0xDDB3E218CB624F3F at byte 2490
# Scores: V/M = 0.00
# Time range: 2014-11-12 16:05:12 to 16:14:23
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          4       6
# Exec time      3    57ms     3ms    14ms    10ms    14ms     4ms     9ms
# Lock time      4     1ms   126us   290us   204us   287us    60us   236us
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine  16  32.34k   5.39k   5.39k   5.39k   5.39k       0   5.39k
# Rows affecte   0       0       0       0       0       0       0       0
# Bytes sent     0  11.43k   1.91k   1.91k   1.91k   1.91k       0   1.91k
# Query size    15   3.86k     658     659  658.83  652.75       0  652.75

#   1us
#  10us
# 100us
#   1ms  ################################################################
#  10ms  ################################
# 100ms
#    1s
#  10s+

I can suggest you to optimize it as mentioned here https://rtcamp.com/tutorials/mysql/mysqltuner/ and https://rtcamp.com/tutorials/mysql/tuning-primer/.

We are not facing any issues related to slow log

Thanks,


#12

THX but I have been using both those tools for years but I have double checked and they don’t suggest any improvements. Maybe this was just a temporary issue… I just mentioned it as I found it in the slow queries log, will watch the issue and report back if I find anything else.


#13