|
Filip Rembiałkowski
wrote:
2009/1/21 Herouth Maoz <herouth@xxxxxxxxxxxxx>
Hello.
I have a daily process that synchronizes our reports database from our
production databases. In the past few days, it happened a couple of
times that an update query took around 7-8 hours to complete, which
seems a bit excessive. This is the query:
UPDATE rb
SET service = b.service,
status = b.status,
has_notification = gateway_id NOT IN (4,101,102),
operator = COALESCE(
b.actual_target_network_id,
b.requested_target_network_id
)
FROM sms.billing b
WHERE b.time_arrived >= :date_start
AND rb.time_stamp >= :date_start
AND rb.delivered = 0
AND rb.sms_user = b.user_id
AND rb.reference = b.user_reference
AND OVERLAY( rb.msisdn placing '972' from 1 for 1 ) = b.msisdn
AND NOT mo_billed
AND system_id <> 6 -- Exclude Corporate, as it aleady has
service/status
;
The variable ":date_start" is set to a date 3 days ago.
I ran explain for this query and it gave me this:
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Nested Loop (cost=21567.12..854759.82 rows=1 width=210)
Join Filter: (((rb.sms_user)::text = (b.user_id)::text) AND
(rb.reference = b.user_reference))
-> Bitmap Heap Scan on rb (cost=21546.02..23946.16 rows=819
width=198)
Recheck Cond: ((delivered = 0) AND (time_stamp >=
'2009-01-18 00:00:00'::timestamp without time zone) AND (time_stamp
< '2009-01-21 00:00:00'::timestamp without time zone))
Filter: ((NOT mo_billed) AND (system_id <> 6))
-> BitmapAnd (cost=21546.02..21546.02 rows=819 width=0)
-> Bitmap Index Scan on rb_delivered_ind
(cost=0.00..1419.99 rows=45768 width=0)
Index Cond: (delivered = 0)
-> Bitmap Index Scan on rb_timestamp_ind
(cost=0.00..20125.37 rows=188994 width=0)
Index Cond: ((time_stamp >= '2009-01-18
00:00:00'::timestamp without time zone) AND (time_stamp <
'2009-01-21 00:00:00'::timestamp without time zone))
-> Bitmap Heap Scan on billing b (cost=21.10..1004.77 rows=351
width=49)
Recheck Cond: ((b.msisdn)::text =
(("substring"((rb.msisdn)::text, 1, 0) || '972'::text) ||
"substring"((rb.msisdn)::text, 2)))
Filter: ((b.time_arrived >= '2009-01-18
00:00:00'::timestamp without time zone) AND (b.time_arrived <
'2009-01-21 00:00:00'::timestamp without time zone))
-> Bitmap Index Scan on billing_msisdn_sme_reference
(cost=0.00..21.10 rows=351 width=0)
Index Cond: ((b.msisdn)::text =
(("substring"((rb.msisdn)::text, 1, 0) || '972'::text) ||
"substring"((rb.msisdn)::text, 2)))
I'm not an expert on reading plans, but it seems to me that it uses
indices on both tables that participate in this query, so it shouldn't
take such a long time.
The number of records in the table rb for the past three days is
386833. On the sms.billing table it seems to select the index on the
msisdn and sme_reference fields and use it partially (only using the
msisdn field). Looking at that table, the frequency of each value in
the msisdn field is at most 17678 for the current data, where mostly
it's a couple of thousands. How can this take so long?
1. which postgres version?
2. can you post results of EXPLAIN ANALYZE (please note it actually
executes the query)?
I'm sorry it took some time to answer these questions - as I explained,
I needed an opportunity to make the change in our production machine
since the data in the development machine wouldn't do at all.
So the answer is PostgreSQL v. 8.3.1. The output of explain analyze is
at the end of this message. Note that the run started at 04:20:50, and
finished at 11:29:30. Also, a full vacuum was ran on the entire
database a day before, and I run analyze on each table whenever there
is a bulk insert or update to it - and the only way data comes in is in
bulks.
Could the delay have anything to do with disk space? The device where
the database is located has around 3G left (98% full). If that's the
problem, I suppose I can add a table space on another device and move
the four largest tables into it, but if it has nothing to do with it,
i'd rather stay on the one device. The machine has 4G of RAM.
I hope someone can clue me in based on the results of explain analyze.
Herouth
QUERY PLAN
------------------------------------------------------------------------------------------------------------------
------------------------------------------
Nested Loop (cost=27968.36..645009.77 rows=1 width=210) (actual
time=57128.573..25674240.262 rows=166844 loops=1
)
Join Filter: (((rb.sms_user)::text = (b.user_id)::text) AND
(rb.reference = b.user_reference))
-> Bitmap Heap Scan on rb (cost=27943.66..29556.78 rows=549
width=198) (actual time=37105.248..54856.430 rows
=151332 loops=1)
Recheck Cond: ((delivered = 0) AND (time_stamp >=
'2009-02-06 00:00:00'::timestamp without time zone))
Filter: ((NOT mo_billed) AND (system_id <> 6))
-> BitmapAnd (cost=27943.66..27943.66 rows=549 width=0)
(actual time=37049.818..37049.818 rows=0 loops=
1)
-> Bitmap Index Scan on rb_delivered_ind
(cost=0.00..884.99 rows=24367 width=0) (actual time=8147
.209..8147.209 rows=871142 loops=1)
Index Cond: (delivered = 0)
-> Bitmap Index Scan on rb_timestamp_ind
(cost=0.00..27058.14 rows=235424 width=0) (actual time=2
8884.578..28884.578 rows=1333295 loops=1)
Index Cond: (time_stamp >= '2009-02-06
00:00:00'::timestamp without time zone)
-> Bitmap Heap Scan on billing b (cost=24.70..1110.35 rows=389
width=49) (actual time=165.740..169.260 rows=1
0 loops=151332)
Recheck Cond: ((b.msisdn)::text =
(("substring"((rb.msisdn)::text, 1, 0) || '972'::text) || "substring"((
rb.msisdn)::text, 2)))
Filter: (b.time_arrived >= '2009-02-06 00:00:00'::timestamp
without time zone)
-> Bitmap Index Scan on billing_msisdn_sme_reference
(cost=0.00..24.70 rows=389 width=0) (actual time=2
1.418..21.418 rows=252 loops=151332)
Index Cond: ((b.msisdn)::text =
(("substring"((rb.msisdn)::text, 1, 0) || '972'::text) || "substrin
g"((rb.msisdn)::text, 2)))
Total runtime: 25720210.772 ms
(16 rows)
|
