[rt-users] Slow PostgreSQL perf with 3.8.7
Jeff Blaine
jblaine at kickflop.net
Wed Sep 22 16:29:40 EDT 2010
On 9/22/2010 4:16 PM, Kenneth Marshall wrote:
> It should be called "default_statistics_target" according to
> the PostgreSQL 8.1 documentation. I would set it to 100 like
> the current 8.4 default and re-analyze the database:
>
> vacuumdb -a -z
>
> You could add a '-v' for more information while it is running.
> You may not have heeded the VACUUM documentation, but you should
> almost never use "VACUUM FULL" but just a simple "VACUUM". The
> FULL variant can cause serious index bloating which can only
> be fixed by running REINDEX. Good luck.
Hm, I don't see such a warning here:
http://www.postgresql.org/docs/8.1/static/sql-vacuum.html
Maybe it's officially-undocumented knowledge of yours from
experience?
The Notes do say the following, but from what I can tell the
only hangup on FULL is that it takes longer and exclusively
locks.
"The FULL option is not recommended for routine use, but
may be useful in special cases. An example is when you
have deleted most of the rows in a table and would like
the table to physically shrink to occupy less disk space.
VACUUM FULL will usually shrink the table more than a
plain VACUUM would."
We *did* in fact RT-Shredder-ify 50% of the tickets 4
weeks ago (bogus tickets from the user's misconfigured code).
At any rate, VACUUM FULL ANALYZE solved the problem, which
should be addressed going forward by auto-vacuum.
Thanks again
> Cheers,
> Ken
>
> On Wed, Sep 22, 2010 at 04:08:08PM -0400, Jeff Blaine wrote:
>> 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