[rt-users] Slower ticket display with RT-IR installed

Ruslan Zakirov ruz at bestpractical.com
Wed Dec 5 14:23:36 EST 2012


On Wed, Dec 5, 2012 at 9:31 PM, ktm at rice.edu <ktm at rice.edu> wrote:
> On Wed, Dec 05, 2012 at 07:55:23PM +0400, Ruslan Zakirov wrote:
>> On Wed, Dec 5, 2012 at 7:11 PM, ktm at rice.edu <ktm at rice.edu> wrote:
>> > Dear RT community,
>> >
>> > I have been trying to track down some ticket display slowdowns for our
>> > upgrade from 3.8.5 to 3.8.13+security patches. One difference in the
>> > new version is that we have the latest RT-IR installed. Now there is
>> > a noticable pause during the population of the ticket metadata right
>> > after the "The Basics" pane. When I enabled query logging in the DB
>> > (postgreSQL), I see almost 700 queries of the type:
>> >
>> > 2012-12-05 08:57:40.365 CSTLOG:  duration: 0.325 ms  statement: SELECT DISTINCT main.* FROM CustomFields main JOIN ObjectCustomFields ObjectCustomFields_1  ON ( ObjectCustomFields_1.CustomField = main.id )  WHERE (LOWER(main.Name) = 'constituency') AND (ObjectCustomFields_1.ObjectId = '28') AND (main.LookupType = 'RT::Queue-RT::Ticket')  ORDER BY main.Disabled ASC  LIMIT 1
>> > 2012-12-05 08:57:40.366 CSTLOG:  duration: 0.512 ms  statement: SELECT DISTINCT main.* FROM CustomFields main JOIN ObjectCustomFields ObjectCustomFields_1  ON ( ObjectCustomFields_1.CustomField = main.id )  WHERE (LOWER(main.Name) = 'constituency') AND (ObjectCustomFields_1.ObjectId = '0') AND (main.LookupType = 'RT::Queue-RT::Ticket')  ORDER BY main.Disabled ASC  LIMIT 1
>> >
>> > That is a .3 seconds total for something that is essentially repeating
>> > the same two queries back to back that take a total of 0.85 ms. Is there
>> > something that I have misconfigured? Any ideas? I have attached the full
>> > set of queries.
>>
>> 1) File a bug, we should try to avoid running this queries for not RTIR tickets.
>> 2) Send explain of the query
>> 3) Optimize execution with an index or two, it shouldn't take that
>> long to load a CF
>>
>
> Hi Ruslan,
>
> I will log a bug report. Here are the EXPLAIN commands for these two queries:

I think Pg may benefit from one of the following indexes:

CREATE INDEX CFS_RUZ1 ON CustomFields(LOWER(Name), LOWER(LookupType));
CREATE INDEX CFS_RUZ1 ON CustomFields(LOWER(LookupType), LOWER(Name));
CREATE INDEX CFS_RUZ1 ON CustomFields(LOWER(Name));

To pick one that is most suitable the following steps should be taken:
1) collect all queries that RT executes during a day or a week
2) grep those that involve CustomFields table
3) analyse the set to pick one index that works in all cases

In any case a ticket on issues.bps would be helpful to track it.

> rt3813=# explain analyze SELECT DISTINCT main.* FROM CustomFields main JOIN ObjectCustomFields ObjectCustomFields_1  ON ( ObjectCustomFields_1.CustomField = main.id )  WHERE (LOWER(main.Name) = 'constituency') AND (ObjectCustomFields_1.ObjectId = '27') AND (main.LookupType = 'RT::Queue-RT::Ticket')  ORDER BY main.Disabled ASC  LIMIT 1;
>                                                                                                       QUERY PLAN
> -----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>  Limit  (cost=3.60..3.64 rows=1 width=99) (actual time=0.051..0.051 rows=0 loops=1)
>    ->  Unique  (cost=3.60..3.64 rows=1 width=99) (actual time=0.050..0.050 rows=0 loops=1)
>          ->  Sort  (cost=3.60..3.61 rows=1 width=99) (actual time=0.049..0.049 rows=0 loops=1)
>                Sort Key: main.disabled, main.id, main.name, main.type, main.description, main.sortorder, main.creator, main.created, main.lastupdatedby, main.lastupdated, main.repeated, main.pattern, main.maxvalues
>                Sort Method: quicksort  Memory: 25kB
>                ->  Nested Loop  (cost=0.00..3.59 rows=1 width=99) (actual time=0.034..0.034 rows=0 loops=1)
>                      ->  Index Scan using objectcustomfields_1 on objectcustomfields objectcustomfields_1  (cost=0.00..1.06 rows=5 width=4) (actual time=0.006..0.008 rows=5 loops=1)
>                            Index Cond: (objectid = 27)
>                      ->  Index Scan using customfields_pkey on customfields main  (cost=0.00..0.48 rows=1 width=99) (actual time=0.004..0.004 rows=0 loops=5)
>                            Index Cond: (id = objectcustomfields_1.customfield)
>                            Filter: (((lookuptype)::text = 'RT::Queue-RT::Ticket'::text) AND (lower((name)::text) = 'constituency'::text))
>                            Rows Removed by Filter: 1
>  Total runtime: 0.107 ms
> (13 rows)
>
> rt3813=# explain analyze SELECT DISTINCT main.* FROM CustomFields main JOIN ObjectCustomFields ObjectCustomFields_1  ON ( ObjectCustomFields_1.CustomField = main.id )  WHERE (LOWER(main.Name) = 'constituency') AND (ObjectCustomFields_1.ObjectId = '0') AND (main.LookupType = 'RT::Queue-RT::Ticket')  ORDER BY main.Disabled ASC  LIMIT 1;
>                                                                                                       QUERY PLAN
> -----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>  Limit  (cost=13.64..13.68 rows=1 width=99) (actual time=0.274..0.274 rows=0 loops=1)
>    ->  Unique  (cost=13.64..13.68 rows=1 width=99) (actual time=0.273..0.273 rows=0 loops=1)
>          ->  Sort  (cost=13.64..13.65 rows=1 width=99) (actual time=0.273..0.273 rows=0 loops=1)
>                Sort Key: main.disabled, main.id, main.name, main.type, main.description, main.sortorder, main.creator, main.created, main.lastupdatedby, main.lastupdated, main.repeated, main.pattern, main.maxvalues
>                Sort Method: quicksort  Memory: 25kB
>                ->  Hash Join  (cost=10.28..13.63 rows=1 width=99) (actual time=0.265..0.265 rows=0 loops=1)
>                      Hash Cond: (objectcustomfields_1.customfield = main.id)
>                      ->  Index Scan using objectcustomfields_1 on objectcustomfields objectcustomfields_1  (cost=0.00..3.16 rows=44 width=4) (actual time=0.005..0.025 rows=43 loops=1)
>                            Index Cond: (objectid = 0)
>                      ->  Hash  (cost=10.25..10.25 rows=1 width=99) (actual time=0.226..0.226 rows=2 loops=1)
>                            Buckets: 1024  Batches: 1  Memory Usage: 1kB
>                            ->  Seq Scan on customfields main  (cost=0.00..10.25 rows=1 width=99) (actual time=0.197..0.223 rows=2 loops=1)
>                                  Filter: (((lookuptype)::text = 'RT::Queue-RT::Ticket'::text) AND (lower((name)::text) = 'constituency'::text))
>                                  Rows Removed by Filter: 258
>  Total runtime: 0.314 ms
> (15 rows)
>
> Regards,
> Ken



-- 
Best regards, Ruslan.



More information about the rt-users mailing list