Обсуждение: Query is stuck

In response to Szymon Guz <mabewlun@gmail.com>:

> 2010/4/13 Satish Burnwal (sburnwal) <sburnwal@cisco.com>
>
> >  I have a query which is not giving me the result even after 30 minutes. I
> > want to know how to detect what is going and what’s wrong ?
> >
> >
> >
> > EXPLAIN query - gives me the following:
> >
> > controlsmartdb=# explain select report_id, dm_ip, dm_mac, dm_user, dm_os,
> > report_time, sys_name,  sys_user, sys_user_domain, ss_key, login_time,
> > role_id, new_vlan_id from repcopy as a where report_time = (select
> > max(report_time) from repcopy as b where a.dm_ip = b.dm_ip and
> > a.dm_user=b.dm_user and b.ss_key != '') and report_status = 0 and dm_user =
> > 'u1';
> >
> >                                                          QUERY PLAN
> >
> >
> >
----------------------------------------------------------------------------------------------------------------------------
> >
> >  Seq Scan on repcopy a  (cost=0.00..1630178118.35 rows=35 width=133)
> >
> >    Filter: ((report_status = 0) AND ((dm_user)::text = 'u1'::text) AND
> > (report_time = (subplan)))
> >
> >    SubPlan
> >
> >      ->  Aggregate  (cost=8151.65..8151.66 rows=1 width=8)
> >
> >            ->  Seq Scan on repcopy b  (cost=0.00..8151.65 rows=1 width=8)
> >
> >                  Filter: ((($0)::text = (dm_ip)::text) AND (($1)::text =
> > (dm_user)::text) AND ((ss_key)::text <> ''::text))
> >
> > (6 rows)
> >
> >
> >
> > But EXPLAIN ANALYSE query hangs (is not giving me any output even after 30
> > minutes).
> >
> >
> >
> > Pg_stat_activity shows this - SELECT procpid, usename, current_query,
> > query_start from pg_stat_activity:
> >
> > 2942 | postgres | select report_id, dm_ip, dm_mac, dm_user, dm_os,
> > report_time, sys_name,  sys_user, sys_user_domain, ss_key, login_time,
> > role_id, new_vlan_id from repcopy as a where report_time = (select
> > max(report_time) from repcopy as b where a.dm_ip = b.dm_ip and
> > a.dm_user=b.dm_user and b.ss_key != '') and report_status = 0 and dm_user =
> > 'u1'; | 2010-04-13 18:20:02.828623+05:30
> >
> >
> >
> >
> >
> > In such a case what can I do ?
> >
> >
> > First things that came to my mind:
>
> 1. Check if the query waits on some lock: add the column `waiting` to the
> above query from pg_stat_activity.
> 2. Run vacuum analyze on the table repcopy

In addition to that, indexes on report_time, report_status, and dm_user
might help.

And your query is not "hung", it's just taking a LOOOOONG time.  Based
on the explain, it could take several hours to complete.  How many
rows are in repcopy?  What is your vacuum schedule?  Do a vacuum verbose,
if the number of dead rows is very high on that table, you may benefit
from doing a VACUUM FULL + REINDEX or CLUSTER on the table.

--
Bill Moran
http://www.potentialtech.com
http://people.collaborativefusion.com/~wmoran/

On Tuesday 13 April 2010 6:03:43 am Satish Burnwal (sburnwal) wrote:
> controlsmartdb=# select * from pg_stat_activity where waiting='t';
>
> ERROR:  column "waiting" does not exist
>
>

From here:
http://www.postgresql.org/docs/8.4/interactive/monitoring-stats.html#MONITORING-STATS-VIEWS

My guess is you are being caught by this;

pg_stat_activity

"Furthermore, these columns are only visible if the user examining the view is a
superuser or the same as the user owning the process being reported on. '

--
Adrian Klaver
adrian.klaver@gmail.com

The information transmitted is intended only for the person or entity to which it is addressed and may contain confidential and/or privileged material. 
Any review, re-transmission, dissemination or other use of or taking of any action in reliance upon,this information by persons or entities other than the intended recipient is prohibited. 
If you received this in error, please contact the sender and delete the material from your computer. 
Microland takes all reasonable steps to ensure that its electronic communications are free from viruses. 
However, given Internet accessibility, the Company cannot accept liability for any virus introduced by this e-mail or any attachment and you are advised to use up-to-date virus checking software. 

We can see from the result of EXPLAIN that your query is very costly to
execute (the important bit is "cost=0.00..1630178118.35").  The fact
that it is doing a sequential scan ("Seq Scan") tells us why it takes so
long.

Without being able to see your data, it is hard to offer suggestions
about how you could improve your query.  But one thing that jumps out at
me is that you have a call to the max() function in your WHERE clause.
In my experience, having a function call in a WHERE clause is very
expensive to execute.  I think you would do best if you can find a
different way to build your query that avoids this handicap.  Maybe a
new index on your table would help too, perhaps a partial index; but
again, this is just guessing without knowing the nature of your data.

Thank you,

Lewis Kapell
Computer Operations
Seton Home Study School



On 4/13/2010 8:58 AM, Satish Burnwal (sburnwal) wrote:
> I have a query which is not giving me the result even after 30 minutes.
> I want to know how to detect what is going and what’s wrong ?
>
> EXPLAIN query - gives me the following:
>
> controlsmartdb=# explain select report_id, dm_ip, dm_mac, dm_user,
> dm_os, report_time, sys_name, sys_user, sys_user_domain, ss_key,
> login_time, role_id, new_vlan_id from repcopy as a where report_time =
> (select max(report_time) from repcopy as b where a.dm_ip = b.dm_ip and
> a.dm_user=b.dm_user and b.ss_key != '') and report_status = 0 and
> dm_user = 'u1';
>
> QUERY PLAN
>
>
----------------------------------------------------------------------------------------------------------------------------
>
> Seq Scan on repcopy a (cost=0.00..1630178118.35 rows=35 width=133)
>
> Filter: ((report_status = 0) AND ((dm_user)::text = 'u1'::text) AND
> (report_time = (subplan)))
>
> SubPlan
>
> -> Aggregate (cost=8151.65..8151.66 rows=1 width=8)
>
> -> Seq Scan on repcopy b (cost=0.00..8151.65 rows=1 width=8)
>
> Filter: ((($0)::text = (dm_ip)::text) AND (($1)::text = (dm_user)::text)
> AND ((ss_key)::text <> ''::text))
>
> (6 rows)
>
> But EXPLAIN ANALYSE query hangs (is not giving me any output even after
> 30 minutes).
>
> Pg_stat_activity shows this - SELECT procpid, usename, current_query,
> query_start from pg_stat_activity:
>
> 2942 | postgres | select report_id, dm_ip, dm_mac, dm_user, dm_os,
> report_time, sys_name, sys_user, sys_user_domain, ss_key, login_time,
> role_id, new_vlan_id from repcopy as a where report_time = (select
> max(report_time) from repcopy as b where a.dm_ip = b.dm_ip and
> a.dm_user=b.dm_user and b.ss_key != '') and report_status = 0 and
> dm_user = 'u1'; | 2010-04-13 18:20:02.828623+05:30
>
> In such a case what can I do ?
>

Lewis Kapell <lkapell@setonhome.org> wrote:

> The fact that it is doing a sequential scan ("Seq Scan") tells us
> why it takes so long.

Well, that and the fact that for each row in one scan of the table,
it scans the entire table again.  :-(

>> select report_id, dm_ip, dm_mac, dm_user, dm_os, report_time,
>> sys_name, sys_user, sys_user_domain, ss_key, login_time, role_id,
>> new_vlan_id from repcopy as a where report_time = (select
>> max(report_time) from repcopy as b where a.dm_ip = b.dm_ip and
>> a.dm_user=b.dm_user and b.ss_key != '') and report_status = 0 and
>> dm_user = 'u1';

I *think* that's equivalent to the following, which might be faster:

select
    report_id, a.dm_ip, dm_mac, dm_user, dm_os, a.report_time,
    sys_name, sys_user, sys_user_domain, ss_key, login_time,
    role_id, new_vlan_id
  from repcopy a
  join (
         select dm_ip, max(report_time) as report_time
           from repcopy
           where b.ss_key != '' and b.dm_user = 'u1'
           group by dm_ip
       ) b
    on (b.dm_ip = a.dm_ip and b.report_time = a.report_time)
  where a.report_status = 0 and a.dm_user = 'u1'
;

-Kevin

I have a similar problem where my query is getting stuck for where long time.
Some times it is getting completed in 30-35 mins and some times it is
running for 5-6 days. This is happening from my application which is running
on tomcat-5-5-33.  If I try the same query from psql console this query gets
completed in 30 sec to 1 minute.

OS: Linux 5.8 - 64 bit
Postgresql version: 8.4.7


The query is:
SELECT encode(audit_history.history_id,'hex') from audit_history join
(select config_state_id, max(compliance_audit_time)
 as enforcement_time from audit_history group by config_state_id)A on
(audit_history.compliance_audit_time = A.enforcement_time AND
 audit_history.config_state_id = A.config_state_id) left join
enforcement_trail on
(audit_history.history_id = enforcement_trail.history_id) where
enforcement_trail.history_id is null
LIMIT 500;

The query plan is:

QUERY PLAN

---------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------
 Limit  (cost=663730.68..765365.22 rows=1 width=17)
   ->  Nested Loop Anti Join  (cost=663730.68..765365.22 rows=1 width=17)
         ->  Hash Join  (cost=663730.68..765357.10 rows=1 width=17)
               Hash Cond: ((a.enforcement_time =
mydb.audit_history.compliance_audit_time)
               AND (a.config_state_id = mydb.audit_history.config_state_id))
               ->  Subquery Scan a  (cost=456217.60..471694.21 rows=28395
width=40)
                     ->  GroupAggregate  (cost=456217.60..471410.26
rows=28395 width=25)
                           ->  Sort  (cost=456217.60..461163.51 rows=1978363
width=25)
                                 Sort Key:
mydb.audit_history.config_state_id
                                 ->  Seq Scan on audit_history
(cost=0.00..161415.63 rows=1978363 width=25)
               ->  Hash  (cost=161415.63..161415.63 rows=1978363 width=42)
                     ->  Seq Scan on audit_history  (cost=0.00..161415.63
rows=1978363 width=42
)
         ->  Index Scan using cm_rpt_enforcment_trail_fkindex1 on
enforcement_trail  (cost=0.00..8.10 rows=1 width=17)
               Index Cond: (mydb.audit_history.history_id =
enforcement_trail.history_id)


This issue is happening only one customer setup and we don't see this issue
in other linux setups.
In general this query gets completed in seconds whether it is from tomcat or
from psql console.
The 'historyid' column is a bytearray which we are encoding with hex.

I have tried reindxing both the tables used in the query but no luck.
stract_output.txt
<http://postgresql.1045698.n5.nabble.com/file/n5756437/stract_output.txt>

Please let me know what is the issue here.




--
View this message in context: http://postgresql.1045698.n5.nabble.com/Query-is-stuck-tp2093817p5756437.html
Sent from the PostgreSQL - admin mailing list archive at Nabble.com.