[rt-users] Poor performance in upgrade from RT2 to RT3
Carl Gibbons
cgibbons at du.edu
Thu Sep 25 17:54:46 EDT 2003
Thanks again for the replies. I tried "EXPLAIN ANALYZE" on the
postgresql query, and it showed two costly sequential scans:
-> Seq Scan on tickets main
(cost=0.00..578.76 rows=1 width=176) (actual time=35.04..97.15 rows=133
loops=1)
Filter: ((effectiveid = id)
AND ("type" = 'ticket'::character varying) AND ((status =
'new'::character varying) OR (status = 'open'::character varying)))
-> Seq Scan on groups groups_1
(cost=0.00..749.70 rows=4077 width=11) (actual time=12.57..493.43
rows=8011 loops=133)
Filter: (("domain" =
'RT::Ticket-Role'::character varying) AND ("type" =
'Requestor'::character varying))
So I created a couple of indexes:
CREATE INDEX tickets_status_type ON tickets (status, type);
CREATE INDEX groups_domain_type ON groups (domain, type);
This reduces the query time from 71 seconds to 34 seconds, and EXPLAIN
ANALYZE shows that the two sequential scans replaced by index scans on
the two new indexes. Unfortunately, this is still about 34 seconds
slower than the snappy response I get from RT2. Please help me figure
out what to try next?
Here's a complete copy of the EXPLAIN ANALYZE output, in case it helps.
- Carl
Limit (cost=1047.83..1047.90 rows=1 width=208) (actual
time=34893.55..34893.62 rows=1 loops=1)
-> Unique (cost=1047.83..1047.90 rows=1 width=208) (actual
time=34893.55..34893.61 rows=1 loops=1)
-> Sort (cost=1047.83..1047.84 rows=1 width=208) (actual
time=34893.54..34893.54 rows=2 loops=1)
Sort Key: main.priority, main.id, main.effectiveid,
main.queue, main."type", main.issuestatement, main.resolution,
main."owner", main.subject, main.initialpriority, main.finalpriority,
main.timeestimated, main.timeworked, main.status, main.timeleft,
main.told, main.starts, main.started, main.due, main.resolved,
main.lastupdatedby, main.lastupdated, main.creator, main.created,
main.disabled
-> Nested Loop (cost=0.00..1047.82 rows=1 width=208)
(actual time=18305.49..34892.70 rows=2 loops=1)
-> Nested Loop (cost=0.00..1041.00 rows=2
width=204) (actual time=228.24..34878.69 rows=411 loops=1)
-> Nested Loop (cost=0.00..1036.77 rows=1
width=196) (actual time=227.89..34852.07 rows=133 loops=1)
-> Nested Loop (cost=0.00..1033.74
rows=1 width=188) (actual time=227.43..34831.60 rows=133 loops=1)
Join Filter: (("outer".id)::text
= ("inner".instance)::text)
-> Index Scan using
tickets_status_type, tickets_status_type on tickets main
(cost=0.00..224.77 rows=1 width=177) (actual time=0.67..15.71 rows=133
loops=1)
Index Cond: (((status =
'new'::character varying) AND ("type" = 'ticket'::character varying)) OR
((status = 'open'::character varying) AND ("type" = 'ticket'::character
varying)))
Filter: ((effectiveid = id)
AND ("type" = 'ticket'::character varying) AND ((status =
'new'::character varying) OR (status = 'open'::character varying)))
-> Index Scan using
groups_domain_type on groups groups_1 (cost=0.00..718.32 rows=6044
width=11) (actual time=0.29..198.54 rows=8011 loops=133)
Index Cond: (("domain" =
'RT::Ticket-Role'::character varying) AND ("type" =
'Requestor'::character varying))
-> Index Scan using principals2 on
principals principals_2 (cost=0.00..3.02 rows=1 width=8) (actual
time=0.09..0.10 rows=1 loops=133)
Index Cond: ("outer".id =
principals_2.objectid)
Filter: (principaltype =
'Group'::character varying)
-> Index Scan using cachedgroupmembers3 on
cachedgroupmembers cachedgroupmembers_3 (cost=0.00..4.09 rows=11
width=8) (actual time=0.05..0.07 rows=3 loops=133)
Index Cond: ("outer".id =
cachedgroupmembers_3.groupid)
-> Index Scan using users_pkey on users users_4
(cost=0.00..3.02 rows=1 width=4) (actual time=0.03..0.03 rows=0 loops=411)
Index Cond: ("outer".memberid = users_4.id)
Filter: (lower((emailaddress)::text) =
'cgibbons at du.edu'::text)
Total runtime: 34895.20 msec
(23 rows)
Carl Gibbons wrote:
> Thanks for the replies. I have since upgraded to RT 3.0.5, and I have
> tuned a few more things in postgresql.conf. Still very slow. I set
> the following in postgresql.conf:
>
> log_statement = true
> log_duration = true
> log_timestamp = true
>
> to reveal the inefficient RT3 query, copied below. I suspect that some
> "create index..." hacking might improve this horrible query, but I'm
> not a DBA and I don't know how to analyze this one. Would somebody on
> this list please help me figure out what to do about this?
>
> - Carl
>
> 2003-09-17 16:19:16 LOG: query: SELECT DISTINCT main.* FROM Tickets
> main , Groups Groups_1, Principals Principals_2, CachedGroupMembers
> CachedGroupMembers_3, Users Users_4 WHERE ((main.EffectiveId =
> main.id)) AND ((main.Type = 'ticket')) AND ( ( (
> (lower(Users_4.EmailAddress) = 'cgibbons at du.edu')AND(Groups_1.Domain =
> 'RT::Ticket-Role')AND(Groups_1.Type =
> 'Requestor')AND(Principals_2.PrincipalType = 'Group') ) ) AND (
> (main.Status = 'new')OR(main.Status = 'open') ) ) AND main.id =
> Groups_1.Instance AND Groups_1.id = Principals_2.ObjectId AND
> Principals_2.id = CachedGroupMembers_3.GroupId AND
> CachedGroupMembers_3.MemberId = Users_4.id ORDER BY main.Priority
> DESC LIMIT 10
> 2003-09-17 16:20:27 LOG: duration: 71.308111 sec
>
> About a couple of weeks ago, Carl Gibbons wrote:
>
>> I am trying to migrate an 8,000+ ticket system.
>>
>> Existing system:
>> Red Hat 7.1
>> perl 5.6.0 installed from RPMs
>> RT 2.0.13
>> Apache 1.3.23/mod_perl 1.23
>> PostgreSQL 7.1.3, installed from RPMs
>> New system:
>> Red Hat ES 2.1
>> perl 5.8.0 (compiled from source)
>> RT 3.0.4
>> Apache 1.3.28/mod_perl 1.28
>> PostgreSQL 7.3.4, compiled from source
>>
>> Both systems are dual-processor 700MHz PIII with 1024MB RAM.
>> (I'm not sure, but I think both have the same SCSI disk and
>> RAID configuration, too.) The rt2-to-rt3-v1.20 tool successfully
>> moved users and tickets from the existing system to the new one.
>>
>> Logging into the RT2 system and clicking on "Home" to display the
>> "25 highest priority tickets I own" takes a fraction of a second.
>>
>> Logging into the RT3 system and clicking on "Home" to display the
>> "10 highest priority tickets I own" takes about 50 seconds.
>>
>> Running "top" on the new RT3 system while I click on "Home" shows
>> that a PostgreSQL "postmaster" process pegs one of the CPUs at 99%
>> throughout those 50 seconds.
>>
>> (I tried increasing the shared_buffers parameter in postgresql.conf,
>> but it did not help.) Any ideas on how to make RT3 give me the
>> fraction-of-a-second response to which I am accustomed?
>>
>> -- Carl Gibbons, Network Security Engineer, University of Denver
>
More information about the rt-users
mailing list