Re: EXPLAIN time difference in real

Поиск
Список
Период
Сортировка
От Michael Monnerie
Тема Re: EXPLAIN time difference in real
Дата
Msg-id 535CE2A4.6060606@is.it-management.at
обсуждение исходный текст
Ответ на Re: EXPLAIN time difference in real  (Tom Lane <tgl@sss.pgh.pa.us>)
Ответы Re: EXPLAIN time difference in real  (Tom Lane <tgl@sss.pgh.pa.us>)
Список pgsql-admin
Am 26.04.2014 20:27, schrieb Tom Lane:
> Could the planning time possibly account for that? How long does a
> plain EXPLAIN of the same query take? regards, tom lane

But I see lots of log entries with this query, all around 1200ms. That's
why I started investigating:
Apr 27 08:00:27 mail2 postgres[18740]: [29-1] 535bffef.4934 PARSE:LOG:
duration: 1151.523 ms  parse 1160283289: SELECT m.message_idnr FROM
dbmail_messages m LEFT JOIN dbmail_physmessage p ON m
Apr 27 08:17:42 mail2 postgres[18740]: [30-1] 535bffef.4934 PARSE:LOG:
duration: 1148.042 ms  parse 866717455: SELECT m.message_idnr FROM
dbmail_messages m LEFT JOIN dbmail_physmessage p ON m.
Apr 27 08:19:40 mail2 postgres[18740]: [31-1] 535bffef.4934 PARSE:LOG:
duration: 1172.965 ms  parse 1037202578: SELECT m.message_idnr FROM
dbmail_messages m LEFT JOIN dbmail_physmessage p ON m
Apr 27 08:31:41 mail2 postgres[18740]: [32-1] 535bffef.4934 PARSE:LOG:
duration: 1153.232 ms  parse 790322190: SELECT m.message_idnr FROM
dbmail_messages m LEFT JOIN dbmail_physmessage p ON m.
Apr 27 08:31:56 mail2 postgres[18740]: [33-1] 535bffef.4934 PARSE:LOG:
duration: 1184.642 ms  parse 1338450192: SELECT m.message_idnr FROM
dbmail_messages m LEFT JOIN dbmail_physmessage p ON m
Apr 27 08:38:27 mail2 postgres[18740]: [34-1] 535bffef.4934 PARSE:LOG:
duration: 1144.726 ms  parse 2071873295: SELECT m.message_idnr FROM
dbmail_messages m LEFT JOIN dbmail_physmessage p ON m
Apr 27 08:50:18 mail2 postgres[18740]: [35-1] 535bffef.4934 PARSE:LOG:
duration: 1168.980 ms  parse 1321777959: SELECT m.message_idnr FROM
dbmail_messages m LEFT JOIN dbmail_physmessage p ON m
Apr 27 09:10:34 mail2 postgres[18740]: [36-1] 535bffef.4934 PARSE:LOG:
duration: 1148.291 ms  parse 930586157: SELECT m.message_idnr FROM
dbmail_messages m LEFT JOIN dbmail_physmessage p ON m.
Apr 27 09:22:03 mail2 postgres[18740]: [37-1] 535bffef.4934 PARSE:LOG:
duration: 1167.311 ms  parse 1114429065: SELECT m.message_idnr FROM
dbmail_messages m LEFT JOIN dbmail_physmessage p ON m
Apr 27 09:46:34 mail2 postgres[18740]: [38-1] 535bffef.4934 PARSE:LOG:
duration: 1156.446 ms  parse 1841623092: SELECT m.message_idnr FROM
dbmail_messages m LEFT JOIN dbmail_physmessage p ON m

Here's the EXPLAIN w/o ANALYZE (exactly the same):
  Nested Loop  (cost=0.00..2713.94 rows=1 width=8)
    Output: m.message_idnr
    ->  Nested Loop  (cost=0.00..2712.49 rows=1 width=16)
          Output: m.message_idnr, h.headervalue_id
          ->  Nested Loop  (cost=0.00..2698.63 rows=49 width=24)
                Output: m.message_idnr, h.headername_id, h.headervalue_id
                ->  Nested Loop  (cost=0.00..2591.60 rows=3 width=24)
                      Output: m.message_idnr, m.physmessage_id, p.id
                      ->  Index Scan using dbmail_messages_1 on
public.dbmail_messages m  (cost=0.00..50.07 rows=365 width=16)
                            Output: m.message_idnr, m.mailbox_idnr,
m.physmessage_id, m.seen_flag, m.answered_flag, m.deleted_flag,
m.flagged_flag, m.recent_flag, m.draft_flag, m.unique_id, m.status
                            Index Cond: (m.mailbox_idnr = 3945)
                      ->  Index Scan using dbmail_physmessage_pkey on
public.dbmail_physmessage p (cost=0.00..6.95 rows=1 width=8)
                            Output: p.id, p.messagesize, p.rfcsize,
p.internal_date
                            Index Cond: (p.id = m.physmessage_id)
                            Filter: (p.internal_date > (now() - '3
days'::interval))
                ->  Index Scan using dbmail_header_pkey on
public.dbmail_header h  (cost=0.00..35.47 rows=16 width=24)
                      Output: h.physmessage_id, h.headername_id,
h.headervalue_id
                      Index Cond: (h.physmessage_id = m.physmessage_id)
          ->  Index Scan using dbmail_headername_pkey on
public.dbmail_headername n  (cost=0.00..0.27 rows=1 width=8)
                Output: n.id, n.headername
                Index Cond: (n.id = h.headername_id)
                Filter: ((n.headername)::text = ANY
('{resent-message-id,message-id}'::text[]))
    ->  Index Scan using dbmail_headervalue_pkey on
public.dbmail_headervalue v  (cost=0.00..1.44 rows=1 width=8)
          Output: v.id, v.hash, v.headervalue, v.sortfield, v.datefield
          Index Cond: (v.id = h.headervalue_id)
          Filter: ("substring"(v.headervalue, 0, 255) = '%e%'::text)
(26 rows)

PS: Is there anything I could possibly optimize in that query by another
index? I don't see anything obvious.

SELECT m.message_idnr FROM dbmail_messages m LEFT JOIN
dbmail_physmessage p ON m.physmessage_id=p.id LEFT JOIN dbmail_header h
ON p.id=h.physmessage_id LEFT JOIN dbmail_headername n ON
h.headername_id=n.id LEFT JOIN dbmail_headervalue v ON
h.headervalue_id=v.id WHERE m.mailbox_idnr=3945 AND n.headername IN
('resent-message-id','message-id') AND
SUBSTRING(v.headervalue,0,255)='%e%' AND p.internal_date > NOW() -
INTERVAL '3 DAY';

--
mit freundlichen Grüssen,
Michael Monnerie, Ing. BSc, Tel: +43 660 415 6531

Protéger.at Internet Services Austria
Web: http://protéger.at und http://proteger.at
Facebook https://facebook.com/protegerat
Mitglied im it-management Netzwerk http://it-management.at



В списке pgsql-admin по дате отправления:

Предыдущее
От: Tom Lane
Дата:
Сообщение: Re: EXPLAIN time difference in real
Следующее
От: Tom Lane
Дата:
Сообщение: Re: EXPLAIN time difference in real