Comment 5 for bug 618356

Revision history for this message
Robert Collins (lifeless) wrote : Re: Person-picker takes a very long time consistently

explain analyze (mostly cold) on qastaging:

 Limit (cost=145627.02..145627.04 rows=7 width=266) (actual time=5228.161..5228.163 rows=1 loops=1)
   -> Sort (cost=145627.02..145627.27 rows=101 width=266) (actual time=5228.158..5228.159 rows=1 loops=1)
         Sort Key: ((person.name = 'david.wonderly'::text)), person.displayname, person.name
         Sort Method: quicksort Memory: 25kB
         -> Subquery Scan person (cost=145622.57..145625.10 rows=101 width=266) (actual time=5227.951..5227.952 rows=1 loops=1)
               -> HashAggregate (cost=145622.57..145623.84 rows=101 width=266) (actual time=5227.937..5227.938 rows=1 loops=1)
                     -> Subquery Scan person (cost=145613.74..145616.01 rows=101 width=266) (actual time=5227.908..5227.910 rows=1 loops=1)
                           -> HashAggregate (cost=145613.74..145614.75 rows=101 width=755) (actual time=5227.872..5227.874 rows=1 loops=1)
                                 -> Append (cost=144443.37..145607.42 rows=101 width=755) (actual time=4925.668..5227.847 rows=1 loops=1)
                                       -> Nested Loop Left Join (cost=144443.37..145182.56 rows=100 width=755) (actual time=4925.667..4925.671 rows=1 loops=1)
                                             Filter: ((NOT (public.person.teamowner IS NULL)) OR (public.emailaddress.status = 4))
                                             -> Nested Loop (cost=144443.37..145080.28 rows=100 width=755) (actual time=4899.215..4899.218 rows=1 loops=1)
                                                   -> HashAggregate (cost=144443.37..144444.37 rows=100 width=4) (actual time=4899.189..4899.190 rows=1 loops=1)
                                                         -> Limit (cost=144441.87..144442.12 rows=100 width=8) (actual time=4899.172..4899.174 rows=3 loops=1)
                                                               -> Sort (cost=144441.87..144458.39 rows=6608 width=8) (actual time=4899.172..4899.172 rows=3 loops=1)
                                                                     Sort Key: public_subquery.rank
                                                                     Sort Method: quicksort Memory: 25kB
                                                                     -> Subquery Scan public_subquery (cost=0.00..144189.32 rows=6608 width=8) (actual time=14.238..4899.083 rows=3 loops=1)
                                                                           -> Append (cost=0.00..144123.24 rows=6608 width=4) (actual time=14.237..4899.080 rows=3 loops=1)
                                                                                 -> Subquery Scan "*SELECT* 1" (cost=0.00..6.42 rows=1 width=4) (actual time=14.236..14.239 rows=1 loops=1)
                                                                                       -> Index Scan using person__name__key on person (cost=0.00..6.41 rows=1 width=4) (actual time=14.210..14.213 rows=1 loops=1)
                                                                                             Index Cond: (name = 'david.wonderly'::text), Person.defaultrenewalperiod, Person.displayname, Person.hide_email_addresses, Person.homepage_content -> Seq Scan on person (cost=0.00..44384.20 rows=5 width=54) (actual time=4671.166..4787.987 rows=1 loops=1)n.registrant, Person.renewal_policy, Person.subsc Filter: ((fti)::tsvector @@ '''david'' & ''wonder'' | ''davidwond'''::tsquery)
                                                                                 -> Subquery Scan "*SELECT* 3" (cost=0.00..1363.76 rows=125 width=4) (actual time=92.152..92.152 rows=0 loops=1)
                                                                                       -> Nested Loop (cost=0.00..1362.51 rows=125 width=4) (actual time=92.149..92.149 rows=0 loops=1), Person.hide_email_addresses, Person.homepage_content -> Seq Scan on ircid (cost=0.00..570.19 rows=125 width=4) (actual time=92.145..92.145 rows=0 loops=1)strant, Person.renewal_policy, Person.subsc Filter: (lower(nickname) = 'david.wonderly'::text)g, Person.personal_standing_reason, Person.registrant, Person.renewal_policy, Person.subsc
                                                                                             -> Index Scan using person_pkey on person (cost=0.00..6.33 rows=1 width=4) (never executed)
                                                                                                   Index Cond: (public.person.id = ircid.person)
                                                                                 -> Subquery Scan "*SELECT* 4" (cost=578.23..98368.80 rows=6477 width=4) (actual time=4.687..4.692 rows=1 loops=1)
                                                                                       -> Nested Loop (cost=578.23..98304.03 rows=6477 width=4) (actual time=4.661..4.666 rows=1 loops=1)
                                                                                             -> Bitmap Heap Scan on emailaddress (cost=578.23..31482.49 rows=22092 width=4) (actual time=0.276..0.278 rows=1 loops=1)
                                                                                                   Filter: ((status = ANY ('{2,4}'::integer[])) AND (lower(email) ~~ 'david.wonderly%%'::text))
                                                                                                   -> Bitmap Index Scan on emailaddress__lower_email__key (cost=0.00..572.71 rows=22376 width=0) (actual time=0.175..0.175 rows=1 loops=1)
                                                                                                         Index Cond: ((lower(email) >= 'david.wonderly'::text) AND (lower(email) < 'david.wonderlz'::text))
                                                                                             -> Index Scan using person_pkey on person (cost=0.00..3.01 rows=1 width=4) (actual time=4.374..4.377 rows=1 loops=1)
                                                                                                   Index Cond: (public.person.id = public.emailaddress.person)
                                                   -> Index Scan using person_pkey on person (cost=0.00..6.35 rows=1 width=755) (actual time=0.020..0.021 rows=1 loops=1)
                                                         Index Cond: (public.person.id = public_subquery.id)
                                                         Filter: ((public.person.merged IS NULL) AND (public.person.visibility = 1))
                                             -> Index Scan using emailaddress__person__status__idx on emailaddress (cost=0.00..0.95 rows=5 width=8) (actual time=17.143..26.437 rows=3 loops=1)
                                                   Index Cond: (public.emailaddress.person = public.person.id)
                                       -> Subquery Scan "*SELECT* 2" (cost=423.85..423.86 rows=1 width=805) (actual time=302.173..302.173 rows=0 loops=1)
                                             -> Limit (cost=423.85..423.85 rows=1 width=805) (actual time=302.172..302.172 rows=0 loops=1)
                                                   -> Sort (cost=423.85..423.85 rows=1 width=805) (actual time=302.168..302.168 rows=0 loops=1)
                                                         Sort Key: (rank((public.person.fti)::tsvector, '''david'' & ''wonder'' | ''davidwond'''::tsquery))
                                                         Sort Method: quicksort Memory: 25kB
                                                         -> Nested Loop (cost=0.00..423.84 rows=1 width=805) (actual time=302.144..302.144 rows=0 loops=1)
                                                               -> Index Scan using teamparticipation_person_idx on teamparticipation (cost=0.00..123.43 rows=47 width=4) (actual time=26.199..146.424 rows=36 loops=1)
                                                                     Index Cond: (person = 3020039)
                                                               -> Index Scan using person_pkey on person (cost=0.00..6.38 rows=1 width=805) (actual time=4.323..4.323 rows=0 loops=36)
                                                                     Index Cond: (public.person.id = teamparticipation.team)
                                                                     Filter: ((NOT (public.person.teamowner IS NULL)) AND ((public.person.fti)::tsvector @@ '''david'' & ''wonder'' | ''davidwond'''::tsquery) AND (public.person.visibility = 30))
 Total runtime: 5228.908 ms