[rt-users] WebRT 3.8.7 Slow Performance
ronald.higgins
ronald.higgins at gmail.com
Mon Apr 19 07:38:32 EDT 2010
Greetings fellow list members.
I'm hoping some more experienced members might be able to shed some light on
some performance issues
we have been having with Request Tracker 3.8.7, it really is terribly slow
loading anything from the DB side without the Server itself being
constrained for resources.
The RT instance is running under VMWare VSphere (ESX4.0) with the following
resources assigned
8 vCPU's
24GB RAM
500GB disk on SAN (the SAN is idling so it's definately not disk I/O)
O.S is Centos 5.4
The database itself (ibdata1) is 213GB in size. The database stores a lot of
images (faxes) sent from customers,
hence the size of the DB. The Tickets table contains about 1.2 million
records.
Once logged into RT the (RT @ a Glance & queues takes about 10->15 seconds
too load.
Pages like Configuration loads instantaneously leading me to believe it's
anything being queried out of the DB.
So any guidance on InnoDB tweaks to try would be appreciated as well.
##################
#MySQL related Info#
##################
#######################################################################################
mysql> show engine innodb status\G;
*************************** 1. row ***************************
Status:
=====================================
100419 11:04:18 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 15 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 11363775, signal count 4598538
Mutex spin waits 0, rounds 1511018468, OS waits 3297606
RW-shared spins 12329291, OS waits 6064081; RW-excl spins 7564941, OS waits
1214997
------------
TRANSACTIONS
------------
Trx id counter 0 1347315994
Purge done for trx's n:o < 0 1347314768 undo n:o < 0 0
History list length 18
Total number of lock structs in row lock hash table 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 0, not started, process no 5371, OS thread id 1183050048
MySQL thread id 924, query id 6013662 localhost root
show engine innodb status
---TRANSACTION 0 1347315694, not started, process no 5371, OS thread id
1173416256
MySQL thread id 923, query id 6012423 localhost rt_user
---TRANSACTION 0 1347315808, not started, process no 5371, OS thread id
1171409216
MySQL thread id 921, query id 6013433 localhost rt_user
---TRANSACTION 0 1347315807, not started, process no 5371, OS thread id
1176828224
MySQL thread id 920, query id 6013424 localhost rt_user
---TRANSACTION 0 1347314770, not started, process no 5371, OS thread id
1180440896
MySQL thread id 919, query id 6008500 localhost rt_user
---TRANSACTION 0 1347315776, not started, process no 5371, OS thread id
1180641600
MySQL thread id 918, query id 6013312 localhost rt_user
---TRANSACTION 0 1347315924, not started, process no 5371, OS thread id
1176426816
MySQL thread id 917, query id 6013592 localhost rt_user
---TRANSACTION 0 1347315841, not started, process no 5371, OS thread id
1174018368
MySQL thread id 916, query id 6013495 localhost rt_user
---TRANSACTION 0 1347315301, not started, process no 5371, OS thread id
1177631040
MySQL thread id 914, query id 6008465 localhost rt_user
---TRANSACTION 0 1347315993, not started, process no 5371, OS thread id
1187264832
MySQL thread id 913, query id 6013661 localhost rt_user
---TRANSACTION 0 1347315752, not started, process no 5371, OS thread id
1184254272
MySQL thread id 840, query id 6013216 localhost rt_user
---TRANSACTION 0 1347315768, not started, process no 5371, OS thread id
1181043008
MySQL thread id 834, query id 6013268 localhost rt_user
---TRANSACTION 0 1347315684, not started, process no 5371, OS thread id
1185659200
MySQL thread id 830, query id 6012355 localhost rt_user
---TRANSACTION 0 1347315775, not started, process no 5371, OS thread id
1083808064
MySQL thread id 813, query id 6013356 localhost rt_user
---TRANSACTION 0 1347315773, not started, process no 5371, OS thread id
1186261312
MySQL thread id 811, query id 6013273 localhost rt_user
---TRANSACTION 0 1347315723, not started, process no 5371, OS thread id
1185458496
MySQL thread id 807, query id 6013245 localhost rt_user
---TRANSACTION 0 1347314764, not started, process no 5371, OS thread id
1186462016
MySQL thread id 806, query id 6008386 localhost rt_user
---TRANSACTION 0 1347315541, not started, process no 5371, OS thread id
1175423296
MySQL thread id 802, query id 6013293 localhost rt_user
---TRANSACTION 0 1347315790, not started, process no 5371, OS thread id
1081203008
MySQL thread id 754, query id 6013327 localhost rt_user
---TRANSACTION 0 1347315801, ACTIVE 2 sec, process no 5371, OS thread id
1079327040 starting index read, thread declared inside InnoDB 283
mysql tables in use 4, locked 0
MySQL thread id 841, query id 6013346 localhost rt_user Copying to tmp table
SELECT DISTINCT main.* FROM Users main CROSS JOIN ACL ACL_2 JOIN Principals
Principals_1 ON ( Principals_1.id = main.id ) JOIN CachedGroupMembers
CachedGroupMembers_3 ON ( CachedGroupMembers_3.MemberId = Principals_1.id )
WHERE (Principals_1.Disabled = '0') AND (ACL_2.PrincipalId =
CachedGroupMembers_3.GroupId) AND (Principals_1.id != '1') AND
(ACL_2.PrincipalType = 'Group') AND (Principals_1.PrincipalType = 'User')
AND (ACL_2.RightName = 'OwnTicket') AND ((ACL_2.ObjectType = 'RT::Queue') OR
(ACL_2.ObjectType = 'RT::System')) ORDER BY main.Name ASC
Trx read view will not see trx with id >= 0 1347315802, sees < 0 1347315215
---TRANSACTION 0 1347315215, ACTIVE 14 sec, process no 5371, OS thread id
1096284480 starting index read, thread declared inside InnoDB 10
mysql tables in use 3, locked 0
MySQL thread id 912, query id 6007074 localhost rt_user Copying to tmp table
SELECT DISTINCT main.* FROM Tickets main CROSS JOIN Users Users_3 JOIN
Groups Groups_1 ON ( Groups_1.Domain = 'RT::Ticket-Role' ) AND (
Groups_1.Type = 'Requestor' ) AND ( Groups_1.Instance = main.id ) JOIN
CachedGroupMembers CachedGroupMembers_2 ON ( CachedGroupMembers_2.MemberId
= Users_3.id ) AND ( CachedGroupMembers_2.GroupId = Groups_1.id ) WHERE
(Users_3.id = '1241833') AND (main.Status != 'deleted') AND ( (
CachedGroupMembers_2.id IS NOT NULL ) AND ( main.Status = 'new' OR
main.Status = 'open' OR main.Status = 'stalled' ) ) AND (main.Type =
'ticket') AND (main.EffectiveId = main.id
Trx read view will not see trx with id >= 0 1347315216, sees < 0 1347314360
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (write thread)
Pending normal aio reads: 0, aio writes: 0,
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
2769582 OS file reads, 93462 OS file writes, 33046 OS fsyncs
0.07 reads/s, 16384 avg bytes/read, 3.00 writes/s, 1.80 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 5, seg size 7,
825 inserts, 825 merged recs, 120 merges
Hash table size 17700857, used cells 13967099, node heap has 40615 buffer(s)
416299.25 hash searches/s, 127302.78 non-hash searches/s
---
LOG
---
Log sequence number 60 1215858005
Log flushed up to 60 1215857995
Last checkpoint at 60 1215430296
0 pending log writes, 0 pending chkp writes
27847 log i/o's done, 1.53 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 9551415920; in additional pool allocated 16775936
Buffer pool size 524288
Free buffers 1
Database pages 483672
Modified db pages 108
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 9488089, created 12107, written 82568
0.07 reads/s, 1.60 creates/s, 1.87 writes/s
Buffer pool hit rate 1000 / 1000
--------------
ROW OPERATIONS
--------------
2 queries inside InnoDB, 0 queries in queue
3 read views open inside InnoDB
Main thread process no. 5371, id 1170004288, state: sleeping
Number of rows inserted 41669, updated 32489, deleted 2390, read 9639755901
4.20 inserts/s, 2.73 updates/s, 0.13 deletes/s, 973193.79 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
1 row in set (0.11 sec)
ERROR:
No query specified
#######################################################################################
mysql> show indexes from Tickets;
+---------+------------+----------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+
| Table | Non_unique | Key_name | Seq_in_index | Column_name | Collation |
Cardinality | Sub_part | Packed | Null | Index_type | Comment |
+---------+------------+----------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+
| Tickets | 0 | PRIMARY | 1 | id | A |
1339471 | NULL | NULL | | BTREE | |
| Tickets | 1 | Tickets1 | 1 | Queue | A |
18 | NULL | NULL | | BTREE | |
| Tickets | 1 | Tickets1 | 2 | Status | A |
18 | NULL | NULL | YES | BTREE | |
| Tickets | 1 | Tickets2 | 1 | Owner | A |
18 | NULL | NULL | | BTREE | |
| Tickets | 1 | Tickets6 | 1 | EffectiveId | A |
1339471 | NULL | NULL | | BTREE | |
| Tickets | 1 | Tickets6 | 2 | Type | A |
1339471 | NULL | NULL | YES | BTREE | |
+---------+------------+----------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+
And some sample queries out of the mysqld-slow log:
# Query_time: 38 Lock_time: 0 Rows_sent: 10 Rows_examined: 1570956
SELECT DISTINCT main.* FROM Tickets main CROSS JOIN Users Users_3 JOIN
Groups Groups_1 ON ( Groups_1.Domain = 'RT::Ticket-Role' ) AND (
Groups_1.Type = 'Requestor' ) AND ( Groups_1.Instance = main.id ) JOIN
CachedGroupMembers CachedGroupMembers_2 ON ( CachedGroupMembers_2.MemberId
= Users_3.id ) AND ( CachedGroupMembers_2.GroupId = Groups_1.id ) WHERE
(Users_3.id = '1241833') AND (main.Status != 'deleted') AND ( (
CachedGroupMembers_2.id IS NOT NULL ) AND ( main.Status = 'new' OR
main.Status = 'open' OR main.Status = 'stalled' ) ) AND (main.Type =
'ticket') AND (main.EffectiveId = main.id) ORDER BY main.Priority DESC
LIMIT 10;
# Time: 100419 11:06:04
# User at Host: rt_user[rt_user] @ localhost []
# Query_time: 10 Lock_time: 0 Rows_sent: 10 Rows_examined: 839782
SELECT main.* FROM Tickets main WHERE (main.Status != 'deleted') AND
(main.Owner = '10' AND ( main.Status = 'new' OR main.Status = 'open' ) )
AND (main.Type = 'ticket') AND (main.EffectiveId = main.id) ORDER BY
main.Created DESC LIMIT 10;
# Time: 100419 11:06:05
# User at Host: rt_user[rt_user] @ localhost []
# Query_time: 9 Lock_time: 0 Rows_sent: 1 Rows_examined: 839772
SELECT count(main.id) FROM Tickets main WHERE (main.Status != 'deleted')
AND (main.Owner = '10' AND ( main.Status = 'new' OR main.Status = 'open' )
) AND (main.Type = 'ticket') AND (main.EffectiveId = main.id);
# User at Host: rt_user[rt_user] @ localhost []
# Query_time: 40 Lock_time: 0 Rows_sent: 10 Rows_examined: 1570956
SELECT DISTINCT main.* FROM Tickets main CROSS JOIN Users Users_3 JOIN
Groups Groups_1 ON ( Groups_1.Domain = 'RT::Ticket-Role' ) AND (
Groups_1.Type = 'Requestor' ) AND ( Groups_1.Instance = main.id ) JOIN
CachedGroupMembers CachedGroupMembers_2 ON ( CachedGroupMembers_2.MemberId
= Users_3.id ) AND ( CachedGroupMembers_2.GroupId = Groups_1.id ) WHERE
(Users_3.id = '1241833') AND (main.Status != 'deleted') AND ( (
CachedGroupMembers_2.id IS NOT NULL ) AND ( main.Status = 'new' OR
main.Status = 'open' OR main.Status = 'stalled' ) ) AND (main.Type =
'ticket') AND (main.EffectiveId = main.id) ORDER BY main.Priority DESC
LIMIT 10;
# Time: 100419 11:06:06
#######################################################################################
#########
#System#
#########
On the O.S side everything looks good, O.S is nippy:
mpstat -P ALL
Linux 2.6.18-164.15.1.el5 04/19/2010
11:09:59 AM CPU %user %nice %sys %iowait %irq %soft %steal
%idle intr/s
11:09:59 AM all 8.99 0.01 1.36 1.32 0.06 0.29 0.00
87.99 555.61
11:09:59 AM 0 8.95 0.03 1.64 4.62 0.05 0.23 0.00
84.48 138.93
11:09:59 AM 1 8.89 0.00 1.07 0.50 0.00 0.02 0.00
89.50 0.00
11:09:59 AM 2 8.88 0.00 1.06 0.35 0.00 0.02 0.00
89.69 0.00
11:09:59 AM 3 9.01 0.00 1.06 0.19 0.00 0.02 0.00
89.72 0.00
11:09:59 AM 4 9.62 0.01 1.17 0.33 0.00 0.02 0.00
88.85 0.00
11:09:59 AM 5 9.25 0.00 1.08 0.33 0.00 0.02 0.00
89.31 2.33
11:09:59 AM 6 9.00 0.01 2.07 3.51 0.07 0.15 0.00
85.19 22.36
11:09:59 AM 7 8.28 0.00 1.73 0.70 0.32 1.79 0.00
87.18 391.98
iostat -x 10
avg-cpu: %user %nice %system %iowait %steal %idle
74.12 0.00 4.54 0.03 0.00 21.32
Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz
avgqu-sz await svctm %util
sda 0.00 249.85 1.10 47.75 8.79 2381.62 48.93
0.27 5.58 1.06 5.19
sda1 0.00 0.00 0.00 0.00 0.00 0.00 0.00
0.00 0.00 0.00 0.00
sda2 0.00 249.85 1.10 47.75 8.79 2381.62 48.93
0.27 5.58 1.06 5.19
Best Regards
Ronald Higgins
--
View this message in context: http://old.nabble.com/WebRT-3.8.7-Slow-Performance-tp28287648p28287648.html
Sent from the Request Tracker - User mailing list archive at Nabble.com.
More information about the rt-users
mailing list