[rt-users] Slow PostgreSQL perf with 3.8.7

Jeff Blaine jblaine at kickflop.net
Wed Sep 22 16:08:08 EDT 2010


Ken,

Thanks for the replies.

I don't see any planner settings in postgresql.conf (so
no I've not changed that).

I've turned on autovacuum as well as log_planner_stats (on
a whim that it might provide useful info based on your lead).

Hmm... given how long 'VACUUM FULL;' is taking now,
maybe I was connected to the default database when I
ran it before starting this thread instead of 'rt3'

*fingers crossed*

On 9/22/2010 3:25 PM, Kenneth Marshall wrote:
> Hi Jeff,
>
> Just a quick glance at your plan seems to indicate that there is
> a fairly wide discrepency between how many results a query returns
> and what the planner thinks the query should return. Have you already
> bumped the planner statistics target to 100 or 200 and then re-analyzed
> the database. I do not think that 8.1 had autovacuum enabled by default
> so you should enable it to keep the statistics updated and run a full
> database-wide re-analyze to update the stats. Then try your query again.
>
> Regards,
> Ken
>
> On Wed, Sep 22, 2010 at 12:57:58PM -0400, Jeff Blaine wrote:
>> We have this in place:
>>
>>      CREATE INDEX ObjectCustomFieldValues3 ON ObjectCustomFieldValues
>> (ObjectId,ObjectType);
>>
>> And I don't see any other suggested indexes in the wiki.
>> Maybe I am missing a certain page?  Should I add these:
>>
>>      http://wiki.bestpractical.com/view/DatabaseIndexes
>>
>> Here's the EXPLAIN for one of the slow statements:
>>
>> rt3=# EXPLAIN ANALYZE SELECT DISTINCT main.id AS id, main.Content AS
>> content, main.ContentType AS contenttype, main.TransactionId AS
>> transactionid, main.ContentEncoding AS contentencoding FROM Attachments
>> main JOIN Transactions Transactions_1  ON ( Transactions_1.id =
>> main.TransactionId ) JOIN Tickets Tickets_2  ON ( Tickets_2.id =
>> Transactions_1.ObjectId )  WHERE (Tickets_2.EffectiveId = '35339') AND
>> (Transactions_1.ObjectType = 'RT::Ticket') AND (main.ContentType =
>> 'text/plain' OR main.ContentType LIKE 'message/%' OR main.ContentType =
>> 'text') ORDER BY main.id ASC;
>>
>>       QUERY PLAN
>> ------------------------------------------------------------------------------------------------------------------------------------------------------------------
>>   Unique  (cost=1033.85..1033.86 rows=1 width=396) (actual
>> time=3720.579..3720.579 rows=1 loops=1)
>>     ->   Sort  (cost=1033.85..1033.85 rows=1 width=396) (actual
>> time=3720.373..3720.373 rows=1 loops=1)
>>           Sort Key: main.id, main.content, main.contenttype,
>> main.transactionid, main.contentencoding
>>           ->   Nested Loop  (cost=17.77..1033.84 rows=1 width=396) (actual
>> time=3569.107..3719.649 rows=1 loops=1)
>>                 ->   Nested Loop  (cost=14.13..383.55 rows=1 width=4) (actual
>> time=3562.353..3717.041 rows=28 loops=1)
>>                       ->   Bitmap Heap Scan on transactions transactions_1
>> (cost=14.13..154.48 rows=38 width=8) (actual time=159.630..1185.953
>> rows=75440 loops=1)
>>                             Recheck Cond: ((objecttype)::text =
>> 'RT::Ticket'::text)
>>                             ->   Bitmap Index Scan on transactions1
>> (cost=0.00..14.13 rows=38 width=0) (actual time=156.409..156.409
>> rows=133079 loops=1)
>>                                   Index Cond: ((objecttype)::text =
>> 'RT::Ticket'::text)
>>                       ->   Index Scan using tickets4 on tickets tickets_2
>> (cost=0.00..6.02 rows=1 width=4) (actual time=0.026..0.026 rows=0
>> loops=75440)
>>                             Index Cond: (tickets_2.id = "outer".objectid)
>>                             Filter: (effectiveid = 35339)
>>                 ->   Bitmap Heap Scan on attachments main (cost=3.63..648.02
>> rows=181 width=396) (actual time=0.078..0.082 rows=0 loops=28)
>>                       Recheck Cond: ("outer".id = main.transactionid)
>>                       Filter: (((contenttype)::text = 'text/plain'::text) OR
>> ((contenttype)::text ~~ 'message/%'::text) OR ((contenttype)::text =
>> 'text'::text))
>>                       ->   Bitmap Index Scan on attachments2 (cost=0.00..3.63
>> rows=181 width=0) (actual time=0.011..0.011 rows=1 loops=28)
>>                             Index Cond: ("outer".id = main.transactionid)
>>   Total runtime: 3722.252 ms
>> (18 rows)
>>
>> rt3=#
>>
>>
>> On 9/22/2010 12:24 PM, Kenneth Marshall wrote:
>>> Hi Jeff,
>>>
>>> Wow, is that version of PostgreSQL old. Certainly there have
>>> been many, many performance improvements since v8.1.x. While
>>> upgrading would help, you really need to run an EXPLAIN ANALYZE
>>> for your slow queries to see if there is a problem area. Also,
>>> you should check to wiki to see if you have all of the recommended
>>> PostgreSQL indexes.
>>>
>>> Some things to check.
>>> Ken
>>>
>>> On Wed, Sep 22, 2010 at 12:12:59PM -0400, Jeff Blaine wrote:
>>>> Please bear with my ignorance on this topic.  I realize
>>>> this isn't a PostgreSQL tuning forum, but since it's RT-related
>>>> I thought I'd ask here.
>>>>
>>>> RT 3.8.7 (and RTFM) with PostgreSQL 8.1.18 via RHELv5 running
>>>> as a VM.
>>>>
>>>> We're experiencing significant delays today with various
>>>> PostgreSQL statements taking longer than 1000ms to complete.
>>>>
>>>> We have 10,000 tickets, 1300 of which are 'open'
>>>>
>>>> Can anyone throw out any ideas, things to check, etc?
>>>> Is this just
>>>>
>>>> Viewing a single ticket results in the following, showing
>>>> only those longer than 1000ms:
>>>>
>>>> LOG:  duration: 1496.023 ms
>>>> LOG:  duration: 1496.023 ms  statement: EXECUTE<unnamed>    [PREPARE:
>>>> SELECT
>>>> DISTINCT main.Id AS id, main.Filename AS filename, main.Headers AS
>>>> headers,
>>>> main.Subject AS subject, main.Parent AS parent, main.ContentEncoding AS
>>>> contentencoding, main.ContentType AS contenttype, main.TransactionId AS
>>>> transactionid, main.Created AS created FROM Attachments main JOIN
>>>> Transactions Transactions_1  ON ( Transactions_1.id = main.TransactionId
>>>> )
>>>> JOIN Tickets Tickets_2  ON ( Tickets_2.id = Transactions_1.ObjectId )
>>>> WHERE (Tickets_2.EffectiveId = '35803') AND (Transactions_1.ObjectType =
>>>> 'RT::Ticket')  ORDER BY main.id ASC ]
>>>> LOG:  duration: 2207.968 ms
>>>> LOG:  duration: 2207.968 ms  statement: EXECUTE<unnamed>    [PREPARE:
>>>> SELECT
>>>> DISTINCT main.* FROM Users main CROSS JOIN ACL ACL_4 JOIN Principals
>>>> Principals_1  ON ( Principals_1.id = main.id ) JOIN CachedGroupMembers
>>>> CachedGroupMembers_2  ON ( CachedGroupMembers_2.MemberId =
>>>> Principals_1.id
>>>> ) JOIN Groups Groups_3 ON ( Groups_3.id = CachedGroupMembers_2.GroupId )
>>>> WHERE (Principals_1.Disabled = '0') AND (ACL_4.PrincipalType =
>>>> Groups_3.Type) AND (Principals_1.id != '1') AND
>>>> (Principals_1.PrincipalType
>>>> = 'User') AND (ACL_4.RightName = 'OwnTicket' OR ACL_4.RightName =
>>>> 'SuperUser') AND (Groups_3.Domain = 'RT::Queue-Role' AND
>>>> Groups_3.Instance
>>>> = '1') AND ((ACL_4.ObjectType = 'RT::Queue' AND ACL_4.ObjectId = 1) OR
>>>> (ACL_4.ObjectType = 'RT::System'))  ORDER BY main.Name ASC ]
>>>> LOG:  duration: 3363.967 ms
>>>> LOG:  duration: 3363.967 ms  statement: EXECUTE<unnamed>    [PREPARE:
>>>> 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' OR ACL_2.RightName = 'SuperUser') AND
>>>> ((ACL_2.ObjectType = 'RT::Queue' AND ACL_2.ObjectId   = 1) OR
>>>> (ACL_2.ObjectType = 'RT::System'))  ORDER BY main.Name ASC ]
>>>> LOG:  duration: 1482.014 ms
>>>> LOG:  duration: 1482.014 ms  statement: EXECUTE<unnamed>    [PREPARE:
>>>> SELECT
>>>> DISTINCT main.id AS id, main.Content AS content, main.ContentType AS
>>>> contenttype, main.TransactionId AS transactionid, main.ContentEncoding AS
>>>> contentencoding FROM Attachments main JOIN Transactions Transactions_1
>>>> ON
>>>> ( Transactions_1.id = main.TransactionId ) JOIN Tickets Tickets_2  ON (
>>>> Tickets_2.id = Transactions_1.ObjectId )  WHERE (Tickets_2.EffectiveId =
>>>> '35803') AND (Transactions_1.ObjectType = 'RT::Ticket') AND
>>>> (main.ContentType = 'text/plain' OR main.ContentType LIKE 'message/%' OR
>>>> main.ContentType = 'text')  ORDER BY main.id ASC ]
>>>> LOG:  duration: 1329.789 ms
>>>> LOG:  duration: 1329.789 ms  statement: EXECUTE<unnamed>    [PREPARE:
>>>> SELECT
>>>> DISTINCT main.* FROM Transactions main JOIN Tickets Tickets_1  ON (
>>>> Tickets_1.id = main.ObjectId )  WHERE (main.ObjectType = 'RT::Ticket')
>>>> AND
>>>> (Tickets_1.EffectiveId = '35803')  ORDER BY main.Created ASC, main.id ASC
>>>> ]
>>>>
>>>>
>>>> # /sbin/sysctl kernel.shmmax kernel.shmall kernel.shmmni kernel.sem
>>>> kernel.shmmax = 4294967296
>>>> kernel.shmall = 2097152
>>>> kernel.shmmni = 4096
>>>> kernel.sem = 250        32000   100     128
>>>> # cat /proc/cpuinfo
>>>> processor       : 0
>>>> vendor_id       : GenuineIntel
>>>> cpu family      : 6
>>>> model           : 15
>>>> model name      : Intel(R) Xeon(R) CPU           X5365  @ 3.00GHz
>>>> stepping        : 1
>>>> cpu MHz         : 2992.499
>>>> cache size      : 4096 KB
>>>> fpu             : yes
>>>> fpu_exception   : yes
>>>> cpuid level     : 10
>>>> wp              : yes
>>>> flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge
>>>> mca
>>>> cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss syscall nx lm
>>>> constant_tsc up pni ssse3 cx16 lahf_lm
>>>> bogomips        : 5984.99
>>>> clflush size    : 64
>>>> cache_alignment : 64
>>>> address sizes   : 40 bits physical, 48 bits virtual
>>>> power management:
>>>>
>>>> # cat /proc/meminfo
>>>> MemTotal:      2059588 kB
>>>> MemFree:        664456 kB
>>>> Buffers:         21620 kB
>>>> Cached:         612024 kB
>>>> SwapCached:      25724 kB
>>>> Active:        1164032 kB
>>>> Inactive:       116264 kB
>>>> HighTotal:           0 kB
>>>> HighFree:            0 kB
>>>> LowTotal:      2059588 kB
>>>> LowFree:        664456 kB
>>>> SwapTotal:     2064376 kB
>>>> SwapFree:      1997364 kB
>>>> Dirty:             400 kB
>>>> Writeback:           0 kB
>>>> AnonPages:      644712 kB
>>>> Mapped:          75512 kB
>>>> Slab:            78748 kB
>>>> PageTables:      16492 kB
>>>> NFS_Unstable:        0 kB
>>>> Bounce:              0 kB
>>>> CommitLimit:   3094168 kB
>>>> Committed_AS:  1383072 kB
>>>> VmallocTotal: 34359738367 kB
>>>> VmallocUsed:    263920 kB
>>>> VmallocChunk: 34359473927 kB
>>>> HugePages_Total:     0
>>>> HugePages_Free:      0
>>>> HugePages_Rsvd:      0
>>>> Hugepagesize:     2048 kB
>>>> #
>>>>
>>>> RT Training in Washington DC, USA on Oct 25&   26 2010
>>>> Last one this year -- Learn how to get the most out of RT!
>>>>
>>>
>>
>



More information about the rt-users mailing list