[Bucardo-general] This doesn't look right...
Michelle Sullivan
michelle at sorbs.net
Wed Jun 30 20:58:27 UTC 2010
Greg Sabino Mullane wrote:
>> Type: pushdelta
>> Source herd/database: sorbs2slave / usmaster
>> Target database: backup_server
>> Tables in sync: 58
>> Last good: 10m 45s (time to run: 20m 18s)
>> Last good time: Jun 27, 2010 17:37:29 Target: backup_server
>> Ins/Upd/Del: 568676 / 0 / 2262
>>
> ...
>
>> Type: swap
>> Source herd/database: sorbs2master / aumaster
>> Target database: usmaster
>> Tables in sync: 58
>> Last good: 1h 15m 43s (time to run: 29m 17s)
>> Last good time: Jun 27, 2010 16:32:39 Target: usmaster
>> Ins/Upd/Del: 33183 / 171 / 0
>>
> ...
>
>> Note the insert counts... how can the delta be more than the swap for
>> inserts... it's all supposed to be in sync....
>>
>
> Hard to say from just this data. What is more disconcerting to me is
> the amount of time the syncs are taking - 20 minutes for half a
> million rows in a pushdelta sync indicates something wrong is
> going on. Do the logs indicate why things are taking so long?
>
Nothing - though I do see extended query times some times.. I have
auto-explain on so lets see:
Jul 1 06:31:10 zyklon postgres[25053]: [3-1] LOG: duration: 68096.612
ms execute dbdpg_p48255_2:
Jul 1 06:31:10 zyklon postgres[25053]: [3-2]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",
Jul 1 06:31:10 zyklon postgres[25053]: [3-3]
t.hostsid ,host,sorbsstatus,sysstatus,sorbshistory
Jul 1 06:31:10 zyklon postgres[25053]: [3-4]
FROM bucardo.bucardo_delta d
Jul 1 06:31:10 zyklon postgres[25053]: [3-5] LEFT
JOIN public.hosts t ON (t.hostsid::int8 = d.rowid::int8)
Jul 1 06:31:10 zyklon postgres[25053]: [3-6]
WHERE d.tablename = 9830287::oid
Jul 1 06:31:10 zyklon postgres[25053]: [3-7]
AND NOT EXISTS (
Jul 1 06:31:10 zyklon postgres[25053]: [3-8]
SELECT 1
Jul 1 06:31:10 zyklon postgres[25053]: [3-9]
FROM bucardo.bucardo_track bt
Jul 1 06:31:10 zyklon postgres[25053]: [3-10]
WHERE d.txntime = bt.txntime
Jul 1 06:31:10 zyklon postgres[25053]: [3-11]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:31:10 zyklon postgres[25053]: [3-12]
AND bt.tablename = 9830287::oid
Jul 1 06:31:10 zyklon postgres[25053]: [3-13]
)
Jul 1 06:31:10 zyklon postgres[25053]: [3-14]
Jul 1 06:31:12 zyklon postgres[25053]: [4-1] LOG: duration: 68096.590
ms plan:
Jul 1 06:31:12 zyklon postgres[25053]: [4-2] Unique
(cost=161574.28..161574.30 rows=1 width=55)
Jul 1 06:31:12 zyklon postgres[25053]: [4-3] -> Sort
(cost=161574.28..161574.28 rows=1 width=55)
Jul 1 06:31:12 zyklon postgres[25053]: [4-4] Sort Key:
d.rowid, t.hostsid, t.host, t.sorbsstatus, t.sysstatus, t.sorbshistory
Jul 1 06:31:12 zyklon postgres[25053]: [4-5] -> Nested
Loop Left Join (cost=60298.20..161574.27 rows=1 width=55)
Jul 1 06:31:12 zyklon postgres[25053]: [4-6] ->
Merge Anti Join (cost=60298.19..161564.98 rows=1 width=8)
Jul 1 06:31:12 zyklon postgres[25053]: [4-7]
Merge Cond: (d.txntime = bt.txntime)
Jul 1 06:31:12 zyklon postgres[25053]: [4-8]
-> Index Scan using bucardo_delta_public_hosts_txn on bucardo_delta d
(cost=0.00..76198.81 rows=569529 width=16)
Jul 1 06:31:12 zyklon postgres[25053]: [4-9]
-> Sort (cost=60298.08..60695.08 rows=158800 width=8)
Jul 1 06:31:12 zyklon postgres[25053]: [4-10]
Sort Key: bt.txntime
Jul 1 06:31:12 zyklon postgres[25053]: [4-11]
-> Bitmap Heap Scan on bucardo_track bt
(cost=7553.26..46580.26 rows=158800 width=8)
Jul 1 06:31:12 zyklon postgres[25053]: [4-12]
Recheck Cond: ((tablename =
9830287::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:31:12 zyklon postgres[25053]: [4-13]
-> Bitmap Index Scan on
bucardo_track_target (cost=0.00..7513.56 rows=158800 width=0)
Jul 1 06:31:12 zyklon postgres[25053]: [4-14]
Index Cond: ((tablename =
9830287::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:31:12 zyklon postgres[25053]: [4-15] ->
Index Scan using hosts_id_key on hosts t (cost=0.00..9.18 rows=1 width=47)
Jul 1 06:31:12 zyklon postgres[25053]: [4-16]
Index Cond: (t.hostsid = (d.rowid)::bigint)
Jul 1 06:31:12 zyklon postgres[25053]: [4-17] STATEMENT:
Jul 1 06:31:12 zyklon postgres[25053]: [4-18]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",
Jul 1 06:31:12 zyklon postgres[25053]: [4-19]
t.evidid ,title,historical,type,immutable,gfionly
Jul 1 06:31:12 zyklon postgres[25053]: [4-20]
FROM bucardo.bucardo_delta d
Jul 1 06:31:12 zyklon postgres[25053]: [4-21] LEFT
JOIN public.evidence t ON (t.evidid::int8 = d.rowid::int8)
Jul 1 06:31:12 zyklon postgres[25053]: [4-22]
WHERE d.tablename = 9830280::oid
Jul 1 06:31:12 zyklon postgres[25053]: [4-23]
AND NOT EXISTS (
Jul 1 06:31:12 zyklon postgres[25053]: [4-24]
SELECT 1
Jul 1 06:31:12 zyklon postgres[25053]: [4-25]
FROM bucardo.bucardo_track bt
Jul 1 06:31:12 zyklon postgres[25053]: [4-26]
WHERE d.txntime = bt.txntime
Jul 1 06:31:12 zyklon postgres[25053]: [4-27]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:31:12 zyklon postgres[25053]: [4-28]
AND bt.tablename = 9830280::oid
Jul 1 06:31:12 zyklon postgres[25053]: [4-29]
)
Jul 1 06:31:12 zyklon postgres[25053]: [4-30]
Jul 1 06:32:35 zyklon postgres[25053]: [5-1] LOG: duration: 82766.729
ms execute dbdpg_p48255_3:
Jul 1 06:32:35 zyklon postgres[25053]: [5-2]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",
Jul 1 06:32:35 zyklon postgres[25053]: [5-3]
t.evidid ,title,historical,type,immutable,gfionly
Jul 1 06:32:35 zyklon postgres[25053]: [5-4]
FROM bucardo.bucardo_delta d
Jul 1 06:32:35 zyklon postgres[25053]: [5-5] LEFT
JOIN public.evidence t ON (t.evidid::int8 = d.rowid::int8)
Jul 1 06:32:35 zyklon postgres[25053]: [5-6]
WHERE d.tablename = 9830280::oid
Jul 1 06:32:35 zyklon postgres[25053]: [5-7]
AND NOT EXISTS (
Jul 1 06:32:35 zyklon postgres[25053]: [5-8]
SELECT 1
Jul 1 06:32:35 zyklon postgres[25053]: [5-9]
FROM bucardo.bucardo_track bt
Jul 1 06:32:35 zyklon postgres[25053]: [5-10]
WHERE d.txntime = bt.txntime
Jul 1 06:32:35 zyklon postgres[25053]: [5-11]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:32:35 zyklon postgres[25053]: [5-12]
AND bt.tablename = 9830280::oid
Jul 1 06:32:35 zyklon postgres[25053]: [5-13]
)
Jul 1 06:32:35 zyklon postgres[25053]: [5-14]
Jul 1 06:32:37 zyklon postgres[25053]: [6-1] LOG: duration: 82766.706
ms plan:
Jul 1 06:32:37 zyklon postgres[25053]: [6-2] Unique
(cost=594967.58..594967.60 rows=1 width=158)
Jul 1 06:32:37 zyklon postgres[25053]: [6-3] -> Sort
(cost=594967.58..594967.58 rows=1 width=158)
Jul 1 06:32:37 zyklon postgres[25053]: [6-4] Sort Key:
d.rowid, t.evidid, t.title, t.historical, t.type, t.immutable, t.gfionly
Jul 1 06:32:37 zyklon postgres[25053]: [6-5] -> Nested
Loop Left Join (cost=128513.41..594967.57 rows=1 width=158)
Jul 1 06:32:37 zyklon postgres[25053]: [6-6] ->
Merge Anti Join (cost=128513.40..594949.54 rows=1 width=8)
Jul 1 06:32:37 zyklon postgres[25053]: [6-7]
Merge Cond: (d.txntime = bt.txntime)
Jul 1 06:32:37 zyklon postgres[25053]: [6-8]
-> Index Scan using bucardo_delta_public_evidence_txn on bucardo_delta
d (cost=0.00..234548.50 rows=1744380 width=16)
Jul 1 06:32:37 zyklon postgres[25053]: [6-9]
-> Materialize (cost=128512.51..170454.90 rows=409194 width=8)
Jul 1 06:32:37 zyklon postgres[25053]: [6-10]
-> Sort (cost=128512.51..129535.50
rows=409194 width=8)
Jul 1 06:32:37 zyklon postgres[25053]: [6-11]
Sort Key: bt.txntime
Jul 1 06:32:37 zyklon postgres[25053]: [6-12]
-> Bitmap Heap Scan on bucardo_track
bt (cost=19455.80..84774.17 rows=409194 width=8)
Jul 1 06:32:37 zyklon postgres[25053]: [6-13]
Recheck Cond: ((tablename =
9830280::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:32:37 zyklon postgres[25053]: [6-14]
-> Bitmap Index Scan on
bucardo_track_target (cost=0.00..19353.50 rows=409194 width=0)
Jul 1 06:32:37 zyklon postgres[25053]: [6-15]
Index Cond: ((tablename =
9830280::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:32:37 zyklon postgres[25053]: [6-16] ->
Index Scan using "Evidence_pkey" on evidence t (cost=0.00..17.92 rows=1
width=150)
Jul 1 06:32:37 zyklon postgres[25053]: [6-17]
Index Cond: (t.evidid = (d.rowid)::bigint)
Jul 1 06:32:37 zyklon postgres[25053]: [6-18] STATEMENT:
Jul 1 06:32:37 zyklon postgres[25053]: [6-19]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",d.rowid2 AS
"BUCARDO_ID2",d.rowid3 AS "BUCARDO_ID3",
Jul 1 06:32:37 zyklon postgres[25053]: [6-20]
t.sid,t.rolesid,t.assigned ,expiry,expiryreason
Jul 1 06:32:37 zyklon postgres[25053]: [6-21]
FROM bucardo.bucardo_delta d
Jul 1 06:32:37 zyklon postgres[25053]: [6-22] LEFT
JOIN public.authorisation t ON (t.sid::int8 = d.rowid::int8 AND
t.rolesid::int8 = d.rowid2::int8 AND t.assigned::timestamptz =
d.rowid3::timestamptz)
Jul 1 06:32:37 zyklon postgres[25053]: [6-23]
WHERE d.tablename = 9830240::oid
Jul 1 06:32:37 zyklon postgres[25053]: [6-24]
AND NOT EXISTS (
Jul 1 06:32:37 zyklon postgres[25053]: [6-25]
SELECT 1
Jul 1 06:32:37 zyklon postgres[25053]: [6-26]
FROM bucardo.bucardo_track bt
Jul 1 06:32:37 zyklon postgres[25053]: [6-27]
WHERE d.txntime = bt.txntime
Jul 1 06:32:37 zyklon postgres[25053]: [6-28]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:32:37 zyklon postgres[25053]: [6-29]
AND bt.tablename = 9830240::oid
Jul 1 06:32:37 zyklon postgres[25053]: [6-30]
)
Jul 1 06:32:37 zyklon postgres[25053]: [6-31]
Jul 1 06:33:54 zyklon postgres[25053]: [7-1] LOG: duration: 70210.626
ms execute dbdpg_p48255_8:
Jul 1 06:33:54 zyklon postgres[25053]: [7-2]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",d.rowid2 AS "BUCARDO_ID2",
Jul 1 06:33:54 zyklon postgres[25053]: [7-3]
t.evidid,t.rawid ,"time",sid,msgid
Jul 1 06:33:54 zyklon postgres[25053]: [7-4]
FROM bucardo.bucardo_delta d
Jul 1 06:33:54 zyklon postgres[25053]: [7-5] LEFT
JOIN public.evid2raw t ON (t.evidid::int8 = d.rowid::int8 AND
t.rawid::int8 = d.rowid2::int8)
Jul 1 06:33:54 zyklon postgres[25053]: [7-6]
WHERE d.tablename = 9830269::oid
Jul 1 06:33:54 zyklon postgres[25053]: [7-7]
AND NOT EXISTS (
Jul 1 06:33:54 zyklon postgres[25053]: [7-8]
SELECT 1
Jul 1 06:33:54 zyklon postgres[25053]: [7-9]
FROM bucardo.bucardo_track bt
Jul 1 06:33:54 zyklon postgres[25053]: [7-10]
WHERE d.txntime = bt.txntime
Jul 1 06:33:54 zyklon postgres[25053]: [7-11]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:33:54 zyklon postgres[25053]: [7-12]
AND bt.tablename = 9830269::oid
Jul 1 06:33:54 zyklon postgres[25053]: [7-13]
)
Jul 1 06:33:54 zyklon postgres[25053]: [7-14]
Jul 1 06:33:56 zyklon postgres[25053]: [8-1] LOG: duration: 70210.573
ms plan:
Jul 1 06:33:56 zyklon postgres[25053]: [8-2] Unique
(cost=265338.24..265338.26 rows=1 width=66)
Jul 1 06:33:56 zyklon postgres[25053]: [8-3] -> Sort
(cost=265338.24..265338.25 rows=1 width=66)
Jul 1 06:33:56 zyklon postgres[25053]: [8-4] Sort Key:
d.rowid, d.rowid2, t.evidid, t.rawid, t."time", t.sid, t.msgid
Jul 1 06:33:56 zyklon postgres[25053]: [8-5] -> Nested
Loop Left Join (cost=127607.75..265338.23 rows=1 width=66)
Jul 1 06:33:56 zyklon postgres[25053]: [8-6] Join
Filter: (t.evidid = (d.rowid)::bigint)
Jul 1 06:33:56 zyklon postgres[25053]: [8-7] ->
Merge Anti Join (cost=127607.74..265320.33 rows=1 width=16)
Jul 1 06:33:56 zyklon postgres[25053]: [8-8]
Merge Cond: (d.txntime = bt.txntime)
Jul 1 06:33:56 zyklon postgres[25053]: [8-9]
-> Index Scan using bucardo_delta_public_evid2raw_txn on bucardo_delta
d (cost=0.00..53762.28 rows=399290 width=24)
Jul 1 06:33:56 zyklon postgres[25053]: [8-10]
-> Materialize (cost=127607.54..169202.25 rows=405802 width=8)
Jul 1 06:33:56 zyklon postgres[25053]: [8-11]
-> Sort (cost=127607.54..128622.05
rows=405802 width=8)
Jul 1 06:33:56 zyklon postgres[25053]: [8-12]
Sort Key: bt.txntime
Jul 1 06:33:56 zyklon postgres[25053]: [8-13]
-> Bitmap Heap Scan on bucardo_track
bt (cost=19293.03..84255.24 rows=405802 width=8)
Jul 1 06:33:56 zyklon postgres[25053]: [8-14]
Recheck Cond: ((tablename =
9830269::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:33:56 zyklon postgres[25053]: [8-15]
-> Bitmap Index Scan on
bucardo_track_target (cost=0.00..19191.58 rows=405802 width=0)
Jul 1 06:33:56 zyklon postgres[25053]: [8-16]
Index Cond: ((tablename =
9830269::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:33:56 zyklon postgres[25053]: [8-17] ->
Index Scan using evid2raw_idx2 on evid2raw t (cost=0.00..17.79 rows=1
width=50)
Jul 1 06:33:56 zyklon postgres[25053]: [8-18]
Index Cond: (t.rawid = (d.rowid2)::bigint)
Jul 1 06:33:56 zyklon postgres[25053]: [8-19] STATEMENT:
Jul 1 06:33:56 zyklon postgres[25053]: [8-20]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",
Jul 1 06:33:56 zyklon postgres[25053]: [8-21]
t.emailid ,email,personal
Jul 1 06:33:56 zyklon postgres[25053]: [8-22]
FROM bucardo.bucardo_delta d
Jul 1 06:33:56 zyklon postgres[25053]: [8-23] LEFT
JOIN public.emails t ON (t.emailid::int8 = d.rowid::int8)
Jul 1 06:33:56 zyklon postgres[25053]: [8-24]
WHERE d.tablename = 9830262::oid
Jul 1 06:33:56 zyklon postgres[25053]: [8-25]
AND NOT EXISTS (
Jul 1 06:33:56 zyklon postgres[25053]: [8-26]
SELECT 1
Jul 1 06:33:56 zyklon postgres[25053]: [8-27]
FROM bucardo.bucardo_track bt
Jul 1 06:33:56 zyklon postgres[25053]: [8-28]
WHERE d.txntime = bt.txntime
Jul 1 06:33:56 zyklon postgres[25053]: [8-29]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:33:56 zyklon postgres[25053]: [8-30]
AND bt.tablename = 9830262::oid
Jul 1 06:33:56 zyklon postgres[25053]: [8-31]
)
Jul 1 06:33:56 zyklon postgres[25053]: [8-32]
Jul 1 06:35:23 zyklon postgres[25053]: [9-1] LOG: duration: 83582.147
ms execute dbdpg_p48255_11:
Jul 1 06:35:23 zyklon postgres[25053]: [9-2]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",d.rowid2 AS "BUCARDO_ID2",
Jul 1 06:35:23 zyklon postgres[25053]: [9-3]
t.evidid,t.hostsid ,delisted,delistedby
Jul 1 06:35:23 zyklon postgres[25053]: [9-4]
FROM bucardo.bucardo_delta d
Jul 1 06:35:23 zyklon postgres[25053]: [9-5] LEFT
JOIN public.hosts2evid t ON (t.evidid::int8 = d.rowid::int8 AND
t.hostsid::int8 = d.rowid2::int8)
Jul 1 06:35:23 zyklon postgres[25053]: [9-6]
WHERE d.tablename = 9830293::oid
Jul 1 06:35:23 zyklon postgres[25053]: [9-7]
AND NOT EXISTS (
Jul 1 06:35:23 zyklon postgres[25053]: [9-8]
SELECT 1
Jul 1 06:35:23 zyklon postgres[25053]: [9-9]
FROM bucardo.bucardo_track bt
Jul 1 06:35:23 zyklon postgres[25053]: [9-10]
WHERE d.txntime = bt.txntime
Jul 1 06:35:23 zyklon postgres[25053]: [9-11]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:35:23 zyklon postgres[25053]: [9-12]
AND bt.tablename = 9830293::oid
Jul 1 06:35:23 zyklon postgres[25053]: [9-13]
)
Jul 1 06:35:23 zyklon postgres[25053]: [9-14]
Jul 1 06:35:26 zyklon postgres[25053]: [10-1] LOG: duration: 83582.124
ms plan:
Jul 1 06:35:26 zyklon postgres[25053]: [10-2] Unique
(cost=473441.91..473441.93 rows=1 width=48)
Jul 1 06:35:26 zyklon postgres[25053]: [10-3] -> Sort
(cost=473441.91..473441.92 rows=1 width=48)
Jul 1 06:35:26 zyklon postgres[25053]: [10-4] Sort Key:
d.rowid, d.rowid2, t.evidid, t.hostsid, t.delisted, t.delistedby
Jul 1 06:35:26 zyklon postgres[25053]: [10-5] -> Nested
Loop Left Join (cost=115838.42..473441.90 rows=1 width=48)
Jul 1 06:35:26 zyklon postgres[25053]: [10-6] ->
Merge Anti Join (cost=115838.41..473427.98 rows=1 width=16)
Jul 1 06:35:26 zyklon postgres[25053]: [10-7]
Merge Cond: (d.txntime = bt.txntime)
Jul 1 06:35:26 zyklon postgres[25053]: [10-8]
-> Index Scan using bucardo_delta_public_hosts2evid_txn on
bucardo_delta d (cost=0.00..186482.45 rows=1390805 width=24)
Jul 1 06:35:26 zyklon postgres[25053]: [10-9]
-> Materialize (cost=115837.78..152900.04 rows=361583 width=8)
Jul 1 06:35:26 zyklon postgres[25053]: [10-10]
-> Sort (cost=115837.78..116741.74
rows=361583 width=8)
Jul 1 06:35:26 zyklon postgres[25053]: [10-11]
Sort Key: bt.txntime
Jul 1 06:35:26 zyklon postgres[25053]: [10-12]
-> Bitmap Heap Scan on bucardo_track
bt (cost=17191.78..77511.00 rows=361583 width=8)
Jul 1 06:35:26 zyklon postgres[25053]: [10-13]
Recheck Cond: ((tablename =
9830293::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:35:26 zyklon postgres[25053]: [10-14]
-> Bitmap Index Scan on
bucardo_track_target (cost=0.00..17101.39 rows=361583 width=0)
Jul 1 06:35:26 zyklon postgres[25053]: [10-15]
Index Cond: ((tablename =
9830293::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:35:26 zyklon postgres[25053]: [10-16] ->
Index Scan using hostsandevid_idx on hosts2evid t (cost=0.01..13.81
rows=1 width=32)
Jul 1 06:35:26 zyklon postgres[25053]: [10-17]
Index Cond: ((t.evidid = (d.rowid)::bigint) AND (t.hostsid =
(d.rowid2)::bigint))
Jul 1 06:35:26 zyklon postgres[25053]: [10-18] STATEMENT:
Jul 1 06:35:26 zyklon postgres[25053]: [10-19]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",
Jul 1 06:35:26 zyklon postgres[25053]: [10-20]
t.mv_name ,v_name,last_refresh
Jul 1 06:35:26 zyklon postgres[25053]: [10-21]
FROM bucardo.bucardo_delta d
Jul 1 06:35:26 zyklon postgres[25053]: [10-22] LEFT
JOIN public.matviews t ON (t.mv_name::name = d.rowid::name)
Jul 1 06:35:26 zyklon postgres[25053]: [10-23]
WHERE d.tablename = 9830302::oid
Jul 1 06:35:26 zyklon postgres[25053]: [10-24]
AND NOT EXISTS (
Jul 1 06:35:26 zyklon postgres[25053]: [10-25]
SELECT 1
Jul 1 06:35:26 zyklon postgres[25053]: [10-26]
FROM bucardo.bucardo_track bt
Jul 1 06:35:26 zyklon postgres[25053]: [10-27]
WHERE d.txntime = bt.txntime
Jul 1 06:35:26 zyklon postgres[25053]: [10-28]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:35:26 zyklon postgres[25053]: [10-29]
AND bt.tablename = 9830302::oid
Jul 1 06:35:26 zyklon postgres[25053]: [10-30]
)
Jul 1 06:35:26 zyklon postgres[25053]: [10-31]
Jul 1 06:36:47 zyklon postgres[25053]: [11-1] LOG: duration: 79447.279
ms execute dbdpg_p48255_13:
Jul 1 06:36:47 zyklon postgres[25053]: [11-2]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",
Jul 1 06:36:47 zyklon postgres[25053]: [11-3]
t.pk
,evidid,netid,rolesid,"time",reason,state,hostsid,nameid,sid,unid,c_sid
Jul 1 06:36:47 zyklon postgres[25053]: [11-4]
FROM bucardo.bucardo_delta d
Jul 1 06:36:47 zyklon postgres[25053]: [11-5] LEFT
JOIN public.audit t ON (t.pk::int8 = d.rowid::int8)
Jul 1 06:36:47 zyklon postgres[25053]: [11-6]
WHERE d.tablename = 9830233::oid
Jul 1 06:36:47 zyklon postgres[25053]: [11-7]
AND NOT EXISTS (
Jul 1 06:36:47 zyklon postgres[25053]: [11-8]
SELECT 1
Jul 1 06:36:47 zyklon postgres[25053]: [11-9]
FROM bucardo.bucardo_track bt
Jul 1 06:36:47 zyklon postgres[25053]: [11-10]
WHERE d.txntime = bt.txntime
Jul 1 06:36:47 zyklon postgres[25053]: [11-11]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:36:47 zyklon postgres[25053]: [11-12]
AND bt.tablename = 9830233::oid
Jul 1 06:36:47 zyklon postgres[25053]: [11-13]
)
Jul 1 06:36:47 zyklon postgres[25053]: [11-14]
Jul 1 06:36:51 zyklon postgres[25053]: [12-1] LOG: duration: 79447.256
ms plan:
Jul 1 06:36:51 zyklon postgres[25053]: [12-2] Unique
(cost=516841.24..516841.28 rows=1 width=96)
Jul 1 06:36:51 zyklon postgres[25053]: [12-3] -> Sort
(cost=516841.24..516841.24 rows=1 width=96)
Jul 1 06:36:51 zyklon postgres[25053]: [12-4] Sort Key:
d.rowid, t.pk, t.evidid, t.netid, t.rolesid, t."time", t.reason,
t.state, t.hostsid, t.nameid, t.sid, t.unid, t.c_sid
Jul 1 06:36:51 zyklon postgres[25053]: [12-5] -> Nested
Loop Left Join (cost=128261.36..516841.23 rows=1 width=96)
Jul 1 06:36:51 zyklon postgres[25053]: [12-6] ->
Merge Anti Join (cost=128261.36..516820.17 rows=1 width=8)
Jul 1 06:36:51 zyklon postgres[25053]: [12-7]
Merge Cond: (d.txntime = bt.txntime)
Jul 1 06:36:51 zyklon postgres[25053]: [12-8]
-> Index Scan using bucardo_delta_public_audit_txn on bucardo_delta d
(cost=0.00..191674.71 rows=1428692 width=16)
Jul 1 06:36:51 zyklon postgres[25053]: [12-9]
-> Materialize (cost=128260.65..170107.09 rows=408258 width=8)
Jul 1 06:36:51 zyklon postgres[25053]: [12-10]
-> Sort (cost=128260.65..129281.29
rows=408258 width=8)
Jul 1 06:36:51 zyklon postgres[25053]: [12-11]
Sort Key: bt.txntime
Jul 1 06:36:51 zyklon postgres[25053]: [12-12]
-> Bitmap Heap Scan on bucardo_track
bt (cost=19410.20..84630.29 rows=408258 width=8)
Jul 1 06:36:51 zyklon postgres[25053]: [12-13]
Recheck Cond: ((tablename =
9830233::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:36:51 zyklon postgres[25053]: [12-14]
-> Bitmap Index Scan on
bucardo_track_target (cost=0.00..19308.14 rows=408258 width=0)
Jul 1 06:36:51 zyklon postgres[25053]: [12-15]
Index Cond: ((tablename =
9830233::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:36:51 zyklon postgres[25053]: [12-16] ->
Index Scan using audit_pkey on audit t (cost=0.00..20.95 rows=1 width=88)
Jul 1 06:36:51 zyklon postgres[25053]: [12-17]
Index Cond: (t.pk = (d.rowid)::bigint)
Jul 1 06:36:51 zyklon postgres[25053]: [12-18] STATEMENT:
Jul 1 06:36:51 zyklon postgres[25053]: [12-19]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",d.rowid2 AS "BUCARDO_ID2",
Jul 1 06:36:51 zyklon postgres[25053]: [12-20]
t.evidid,t.netid ,delisted,delistedby
Jul 1 06:36:51 zyklon postgres[25053]: [12-21]
FROM bucardo.bucardo_delta d
Jul 1 06:36:51 zyklon postgres[25053]: [12-22] LEFT
JOIN public.nets2evid t ON (t.evidid::int8 = d.rowid::int8 AND
t.netid::int8 = d.rowid2::int8)
Jul 1 06:36:51 zyklon postgres[25053]: [12-23]
WHERE d.tablename = 9830315::oid
Jul 1 06:36:51 zyklon postgres[25053]: [12-24]
AND NOT EXISTS (
Jul 1 06:36:51 zyklon postgres[25053]: [12-25]
SELECT 1
Jul 1 06:36:51 zyklon postgres[25053]: [12-26]
FROM bucardo.bucardo_track bt
Jul 1 06:36:51 zyklon postgres[25053]: [12-27]
WHERE d.txntime = bt.txntime
Jul 1 06:36:51 zyklon postgres[25053]: [12-28]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:36:51 zyklon postgres[25053]: [12-29]
AND bt.tablename = 9830315::oid
Jul 1 06:36:51 zyklon postgres[25053]: [12-30]
)
Jul 1 06:36:51 zyklon postgres[25053]: [12-31]
Jul 1 06:37:52 zyklon postgres[25053]: [13-1] LOG: duration: 60597.600
ms execute dbdpg_p48255_14:
Jul 1 06:37:52 zyklon postgres[25053]: [13-2]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",d.rowid2 AS "BUCARDO_ID2",
Jul 1 06:37:52 zyklon postgres[25053]: [13-3]
t.evidid,t.netid ,delisted,delistedby
Jul 1 06:37:52 zyklon postgres[25053]: [13-4]
FROM bucardo.bucardo_delta d
Jul 1 06:37:52 zyklon postgres[25053]: [13-5] LEFT
JOIN public.nets2evid t ON (t.evidid::int8 = d.rowid::int8 AND
t.netid::int8 = d.rowid2::int8)
Jul 1 06:37:52 zyklon postgres[25053]: [13-6]
WHERE d.tablename = 9830315::oid
Jul 1 06:37:52 zyklon postgres[25053]: [13-7]
AND NOT EXISTS (
Jul 1 06:37:52 zyklon postgres[25053]: [13-8]
SELECT 1
Jul 1 06:37:52 zyklon postgres[25053]: [13-9]
FROM bucardo.bucardo_track bt
Jul 1 06:37:52 zyklon postgres[25053]: [13-10]
WHERE d.txntime = bt.txntime
Jul 1 06:37:52 zyklon postgres[25053]: [13-11]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:37:52 zyklon postgres[25053]: [13-12]
AND bt.tablename = 9830315::oid
Jul 1 06:37:52 zyklon postgres[25053]: [13-13]
)
Jul 1 06:37:52 zyklon postgres[25053]: [13-14]
Jul 1 06:37:56 zyklon postgres[25053]: [14-1] LOG: duration: 60597.571
ms plan:
Jul 1 06:37:56 zyklon postgres[25053]: [14-2] Unique
(cost=266842.00..266842.02 rows=1 width=48)
Jul 1 06:37:56 zyklon postgres[25053]: [14-3] -> Sort
(cost=266842.00..266842.01 rows=1 width=48)
Jul 1 06:37:56 zyklon postgres[25053]: [14-4] Sort Key:
d.rowid, d.rowid2, t.evidid, t.netid, t.delisted, t.delistedby
Jul 1 06:37:56 zyklon postgres[25053]: [14-5] -> Nested
Loop Left Join (cost=128917.78..266841.99 rows=1 width=48)
Jul 1 06:37:56 zyklon postgres[25053]: [14-6] Join
Filter: (t.netid = (d.rowid2)::bigint)
Jul 1 06:37:56 zyklon postgres[25053]: [14-7] ->
Merge Anti Join (cost=128917.78..266824.19 rows=1 width=16)
Jul 1 06:37:56 zyklon postgres[25053]: [14-8]
Merge Cond: (d.txntime = bt.txntime)
Jul 1 06:37:56 zyklon postgres[25053]: [14-9]
-> Index Scan using bucardo_delta_public_nets2evid_txn on bucardo_delta
d (cost=0.00..53325.66 rows=395722 width=24)
Jul 1 06:37:56 zyklon postgres[25053]: [14-10]
-> Materialize (cost=128917.57..171015.86 rows=410715 width=8)
Jul 1 06:37:56 zyklon postgres[25053]: [14-11]
-> Sort (cost=128917.57..129944.36
rows=410715 width=8)
Jul 1 06:37:56 zyklon postgres[25053]: [14-12]
Sort Key: bt.txntime
Jul 1 06:37:56 zyklon postgres[25053]: [14-13]
-> Bitmap Heap Scan on bucardo_track
bt (cost=19527.39..85005.46 rows=410715 width=8)
Jul 1 06:37:56 zyklon postgres[25053]: [14-14]
Recheck Cond: ((tablename =
9830315::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:37:56 zyklon postgres[25053]: [14-15]
-> Bitmap Index Scan on
bucardo_track_target (cost=0.00..19424.71 rows=410715 width=0)
Jul 1 06:37:56 zyklon postgres[25053]: [14-16]
Index Cond: ((tablename =
9830315::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:37:56 zyklon postgres[25053]: [14-17] ->
Index Scan using nets2evid_idx2 on nets2evid t (cost=0.00..17.69 rows=1
width=32)
Jul 1 06:37:56 zyklon postgres[25053]: [14-18]
Index Cond: (t.evidid = (d.rowid)::bigint)
Jul 1 06:37:56 zyklon postgres[25053]: [14-19] STATEMENT:
Jul 1 06:37:56 zyklon postgres[25053]: [14-20]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",
Jul 1 06:37:56 zyklon postgres[25053]: [14-21]
t.netblock ,hits
Jul 1 06:37:56 zyklon postgres[25053]: [14-22]
FROM bucardo.bucardo_delta d
Jul 1 06:37:56 zyklon postgres[25053]: [14-23] LEFT
JOIN public.most_recent_nets_cached t ON (t.netblock::ip4r = d.rowid::ip4r)
Jul 1 06:37:56 zyklon postgres[25053]: [14-24]
WHERE d.tablename = 9830325::oid
Jul 1 06:37:56 zyklon postgres[25053]: [14-25]
AND NOT EXISTS (
Jul 1 06:37:56 zyklon postgres[25053]: [14-26]
SELECT 1
Jul 1 06:37:56 zyklon postgres[25053]: [14-27]
FROM bucardo.bucardo_track bt
Jul 1 06:37:56 zyklon postgres[25053]: [14-28]
WHERE d.txntime = bt.txntime
Jul 1 06:37:56 zyklon postgres[25053]: [14-29]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:37:56 zyklon postgres[25053]: [14-30]
AND bt.tablename = 9830325::oid
Jul 1 06:37:56 zyklon postgres[25053]: [14-31]
)
Jul 1 06:37:56 zyklon postgres[25053]: [14-32]
Jul 1 06:38:52 zyklon postgres[25053]: [15-1] LOG: duration: 48089.218
ms execute dbdpg_p48255_20:
Jul 1 06:38:52 zyklon postgres[25053]: [15-2]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",
Jul 1 06:38:52 zyklon postgres[25053]: [15-3]
t.netid
,netblock,sorbsstatus,sysstatus,sorbshistory
Jul 1 06:38:52 zyklon postgres[25053]: [15-4]
FROM bucardo.bucardo_delta d
Jul 1 06:38:52 zyklon postgres[25053]: [15-5] LEFT
JOIN public.networks t ON (t.netid::int8 = d.rowid::int8)
Jul 1 06:38:52 zyklon postgres[25053]: [15-6]
WHERE d.tablename = 9830318::oid
Jul 1 06:38:52 zyklon postgres[25053]: [15-7]
AND NOT EXISTS (
Jul 1 06:38:52 zyklon postgres[25053]: [15-8]
SELECT 1
Jul 1 06:38:52 zyklon postgres[25053]: [15-9]
FROM bucardo.bucardo_track bt
Jul 1 06:38:52 zyklon postgres[25053]: [15-10]
WHERE d.txntime = bt.txntime
Jul 1 06:38:52 zyklon postgres[25053]: [15-11]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:38:52 zyklon postgres[25053]: [15-12]
AND bt.tablename = 9830318::oid
Jul 1 06:38:52 zyklon postgres[25053]: [15-13]
)
Jul 1 06:38:52 zyklon postgres[25053]: [15-14]
Jul 1 06:38:56 zyklon postgres[25053]: [16-1] LOG: duration: 48089.198
ms plan:
Jul 1 06:38:56 zyklon postgres[25053]: [16-2] Unique
(cost=103239.16..103239.18 rows=1 width=44)
Jul 1 06:38:56 zyklon postgres[25053]: [16-3] -> Sort
(cost=103239.16..103239.17 rows=1 width=44)
Jul 1 06:38:56 zyklon postgres[25053]: [16-4] Sort Key:
d.rowid, t.netid, t.netblock, t.sorbsstatus, t.sysstatus, t.sorbshistory
Jul 1 06:38:56 zyklon postgres[25053]: [16-5] -> Nested
Loop Left Join (cost=67687.53..103239.15 rows=1 width=44)
Jul 1 06:38:56 zyklon postgres[25053]: [16-6] ->
Merge Anti Join (cost=67687.52..103229.17 rows=1 width=8)
Jul 1 06:38:56 zyklon postgres[25053]: [16-7]
Merge Cond: (d.txntime = bt.txntime)
Jul 1 06:38:56 zyklon postgres[25053]: [16-8]
-> Index Scan using bucardo_delta_public_networks_txn on bucardo_delta
d (cost=0.00..25294.91 rows=188006 width=16)
Jul 1 06:38:56 zyklon postgres[25053]: [16-9]
-> Sort (cost=67687.43..68159.29 rows=188746 width=8)
Jul 1 06:38:56 zyklon postgres[25053]: [16-10]
Sort Key: bt.txntime
Jul 1 06:38:56 zyklon postgres[25053]: [16-11]
-> Bitmap Heap Scan on bucardo_track bt
(cost=8976.20..51147.53 rows=188746 width=8)
Jul 1 06:38:56 zyklon postgres[25053]: [16-12]
Recheck Cond: ((tablename =
9830318::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:38:56 zyklon postgres[25053]: [16-13]
-> Bitmap Index Scan on
bucardo_track_target (cost=0.00..8929.02 rows=188746 width=0)
Jul 1 06:38:56 zyklon postgres[25053]: [16-14]
Index Cond: ((tablename =
9830318::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:38:56 zyklon postgres[25053]: [16-15] ->
Index Scan using "Networks_pkey" on networks t (cost=0.00..9.88 rows=1
width=36)
Jul 1 06:38:56 zyklon postgres[25053]: [16-16]
Index Cond: (t.netid = (d.rowid)::bigint)
Jul 1 06:38:56 zyklon postgres[25053]: [16-17] STATEMENT:
Jul 1 06:38:56 zyklon postgres[25053]: [16-18]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",
Jul 1 06:38:56 zyklon postgres[25053]: [16-19]
t.id ,userid,userauth,usertype,userparent
Jul 1 06:38:56 zyklon postgres[25053]: [16-20]
FROM bucardo.bucardo_delta d
Jul 1 06:38:56 zyklon postgres[25053]: [16-21] LEFT
JOIN public.users t ON (t.id::int8 = d.rowid::int8)
Jul 1 06:38:56 zyklon postgres[25053]: [16-22]
WHERE d.tablename = 9830423::oid
Jul 1 06:38:56 zyklon postgres[25053]: [16-23]
AND NOT EXISTS (
Jul 1 06:38:56 zyklon postgres[25053]: [16-24]
SELECT 1
Jul 1 06:38:56 zyklon postgres[25053]: [16-25]
FROM bucardo.bucardo_track bt
Jul 1 06:38:56 zyklon postgres[25053]: [16-26]
WHERE d.txntime = bt.txntime
Jul 1 06:38:56 zyklon postgres[25053]: [16-27]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:38:56 zyklon postgres[25053]: [16-28]
AND bt.tablename = 9830423::oid
Jul 1 06:38:56 zyklon postgres[25053]: [16-29]
)
Jul 1 06:38:56 zyklon postgres[25053]: [16-30]
Jul 1 06:43:17 zyklon postgres[25053]: [17-1] LOG: duration:
255829.559 ms execute dbdpg_p48255_24:
Jul 1 06:43:17 zyklon postgres[25053]: [17-2]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",
Jul 1 06:43:17 zyklon postgres[25053]: [17-3]
t.rawid
,msgid,msgdeliverer,msgsender,msgchksum,msgreceived,msgbody
Jul 1 06:43:17 zyklon postgres[25053]: [17-4]
FROM bucardo.bucardo_delta d
Jul 1 06:43:17 zyklon postgres[25053]: [17-5] LEFT
JOIN public.rawevidence t ON (t.rawid::int8 = d.rowid::int8)
Jul 1 06:43:17 zyklon postgres[25053]: [17-6]
WHERE d.tablename = 9830363::oid
Jul 1 06:43:17 zyklon postgres[25053]: [17-7]
AND NOT EXISTS (
Jul 1 06:43:17 zyklon postgres[25053]: [17-8]
SELECT 1
Jul 1 06:43:17 zyklon postgres[25053]: [17-9]
FROM bucardo.bucardo_track bt
Jul 1 06:43:17 zyklon postgres[25053]: [17-10]
WHERE d.txntime = bt.txntime
Jul 1 06:43:17 zyklon postgres[25053]: [17-11]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:43:17 zyklon postgres[25053]: [17-12]
AND bt.tablename = 9830363::oid
Jul 1 06:43:17 zyklon postgres[25053]: [17-13]
)
Jul 1 06:43:17 zyklon postgres[25053]: [17-14]
Jul 1 06:43:19 zyklon postgres[25053]: [18-1] LOG: duration:
255829.534 ms plan:
Jul 1 06:43:19 zyklon postgres[25053]: [18-2] Unique
(cost=260312.70..260312.73 rows=1 width=563)
Jul 1 06:43:19 zyklon postgres[25053]: [18-3] -> Sort
(cost=260312.70..260312.71 rows=1 width=563)
Jul 1 06:43:19 zyklon postgres[25053]: [18-4] Sort Key:
d.rowid, t.rawid, t.msgid, t.msgdeliverer, t.msgsender, t.msgchksum,
t.msgreceived, t.msgbody
Jul 1 06:43:19 zyklon postgres[25053]: [18-5] -> Nested
Loop Left Join (cost=127483.84..260312.69 rows=1 width=563)
Jul 1 06:43:19 zyklon postgres[25053]: [18-6] ->
Merge Anti Join (cost=127483.83..260294.65 rows=1 width=8)
Jul 1 06:43:19 zyklon postgres[25053]: [18-7]
Merge Cond: (d.txntime = bt.txntime)
Jul 1 06:43:19 zyklon postgres[25053]: [18-8]
-> Index Scan using bucardo_delta_public_rawevidence_txn on
bucardo_delta d (cost=0.00..51151.60 rows=378066 width=16)
Jul 1 06:43:19 zyklon postgres[25053]: [18-9]
-> Materialize (cost=127483.63..169030.37 rows=405334 width=8)
Jul 1 06:43:19 zyklon postgres[25053]: [18-10]
-> Sort (cost=127483.63..128496.97
rows=405334 width=8)
Jul 1 06:43:19 zyklon postgres[25053]: [18-11]
Sort Key: bt.txntime
Jul 1 06:43:19 zyklon postgres[25053]: [18-12]
-> Bitmap Heap Scan on bucardo_track
bt (cost=19272.23..84185.30 rows=405334 width=8)
Jul 1 06:43:19 zyklon postgres[25053]: [18-13]
Recheck Cond: ((tablename =
9830363::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:43:19 zyklon postgres[25053]: [18-14]
-> Bitmap Index Scan on
bucardo_track_target (cost=0.00..19170.90 rows=405334 width=0)
Jul 1 06:43:19 zyklon postgres[25053]: [18-15]
Index Cond: ((tablename =
9830363::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:43:19 zyklon postgres[25053]: [18-16] ->
Index Scan using rawrvidence_id_key on rawevidence t (cost=0.00..17.93
rows=1 width=555)
Jul 1 06:43:19 zyklon postgres[25053]: [18-17]
Index Cond: (t.rawid = (d.rowid)::bigint)
Jul 1 06:43:19 zyklon postgres[25053]: [18-18] STATEMENT:
Jul 1 06:43:19 zyklon postgres[25053]: [18-19]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",d.rowid2 AS
"BUCARDO_ID2",d.rowid3 AS "BUCARDO_ID3",
Jul 1 06:43:19 zyklon postgres[25053]: [18-20]
t.netid,t.evidid,t.req_ts ,sent,ts
Jul 1 06:43:19 zyklon postgres[25053]: [18-21]
FROM bucardo.bucardo_delta d
Jul 1 06:43:19 zyklon postgres[25053]: [18-22] LEFT
JOIN public.reportq t ON (t.netid::int8 = d.rowid::int8 AND
t.evidid::int8 = d.rowid2::int8 AND t.req_ts::timestamptz =
d.rowid3::timestamptz)
Jul 1 06:43:19 zyklon postgres[25053]: [18-23]
WHERE d.tablename = 9830375::oid
Jul 1 06:43:19 zyklon postgres[25053]: [18-24]
AND NOT EXISTS (
Jul 1 06:43:19 zyklon postgres[25053]: [18-25]
SELECT 1
Jul 1 06:43:19 zyklon postgres[25053]: [18-26]
FROM bucardo.bucardo_track bt
Jul 1 06:43:19 zyklon postgres[25053]: [18-27]
WHERE d.txntime = bt.txntime
Jul 1 06:43:19 zyklon postgres[25053]: [18-28]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:43:19 zyklon postgres[25053]: [18-29]
AND bt.tablename = 9830375::oid
Jul 1 06:43:19 zyklon postgres[25053]: [18-30]
)
Jul 1 06:43:19 zyklon postgres[25053]: [18-31]
Jul 1 06:44:23 zyklon postgres[25053]: [19-1] LOG: duration: 63331.184
ms execute dbdpg_p48255_25:
Jul 1 06:44:23 zyklon postgres[25053]: [19-2]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",d.rowid2 AS
"BUCARDO_ID2",d.rowid3 AS "BUCARDO_ID3",
Jul 1 06:44:23 zyklon postgres[25053]: [19-3]
t.netid,t.evidid,t.req_ts ,sent,ts
Jul 1 06:44:23 zyklon postgres[25053]: [19-4]
FROM bucardo.bucardo_delta d
Jul 1 06:44:23 zyklon postgres[25053]: [19-5] LEFT
JOIN public.reportq t ON (t.netid::int8 = d.rowid::int8 AND
t.evidid::int8 = d.rowid2::int8 AND t.req_ts::timestamptz =
d.rowid3::timestamptz)
Jul 1 06:44:23 zyklon postgres[25053]: [19-6]
WHERE d.tablename = 9830375::oid
Jul 1 06:44:23 zyklon postgres[25053]: [19-7]
AND NOT EXISTS (
Jul 1 06:44:23 zyklon postgres[25053]: [19-8]
SELECT 1
Jul 1 06:44:23 zyklon postgres[25053]: [19-9]
FROM bucardo.bucardo_track bt
Jul 1 06:44:23 zyklon postgres[25053]: [19-10]
WHERE d.txntime = bt.txntime
Jul 1 06:44:23 zyklon postgres[25053]: [19-11]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:44:23 zyklon postgres[25053]: [19-12]
AND bt.tablename = 9830375::oid
Jul 1 06:44:23 zyklon postgres[25053]: [19-13]
)
Jul 1 06:44:23 zyklon postgres[25053]: [19-14]
Jul 1 06:44:25 zyklon postgres[25053]: [20-1] LOG: duration: 63331.155
ms plan:
Jul 1 06:44:25 zyklon postgres[25053]: [20-2] Unique
(cost=265234.76..265234.78 rows=1 width=78)
Jul 1 06:44:25 zyklon postgres[25053]: [20-3] -> Sort
(cost=265234.76..265234.76 rows=1 width=78)
Jul 1 06:44:25 zyklon postgres[25053]: [20-4] Sort Key:
d.rowid, d.rowid2, d.rowid3, t.netid, t.evidid, t.req_ts, t.sent, t.ts
Jul 1 06:44:25 zyklon postgres[25053]: [20-5] -> Nested
Loop Left Join (cost=129351.91..265234.75 rows=1 width=78)
Jul 1 06:44:25 zyklon postgres[25053]: [20-6] Join
Filter: ((t.netid = (d.rowid)::bigint) AND (t.req_ts =
(d.rowid3)::timestamp with time zone))
Jul 1 06:44:25 zyklon postgres[25053]: [20-7] ->
Merge Anti Join (cost=129351.91..265217.06 rows=1 width=45)
Jul 1 06:44:25 zyklon postgres[25053]: [20-8]
Merge Cond: (d.txntime = bt.txntime)
Jul 1 06:44:25 zyklon postgres[25053]: [20-9]
-> Index Scan using bucardo_delta_public_reportq_txn on bucardo_delta
d (cost=0.00..52047.71 rows=385298 width=53)
Jul 1 06:44:25 zyklon postgres[25053]: [20-10]
-> Materialize (cost=129351.70..171617.78 rows=412352 width=8)
Jul 1 06:44:25 zyklon postgres[25053]: [20-11]
-> Sort (cost=129351.70..130382.58
rows=412352 width=8)
Jul 1 06:44:25 zyklon postgres[25053]: [20-12]
Sort Key: bt.txntime
Jul 1 06:44:25 zyklon postgres[25053]: [20-13]
-> Bitmap Heap Scan on bucardo_track
bt (cost=19604.17..85254.13 rows=412352 width=8)
Jul 1 06:44:25 zyklon postgres[25053]: [20-14]
Recheck Cond: ((tablename =
9830375::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:44:25 zyklon postgres[25053]: [20-15]
-> Bitmap Index Scan on
bucardo_track_target (cost=0.00..19501.08 rows=412352 width=0)
Jul 1 06:44:25 zyklon postgres[25053]: [20-16]
Index Cond: ((tablename =
9830375::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:44:25 zyklon postgres[25053]: [20-17] ->
Index Scan using reportq_evidid_idx on reportq t (cost=0.00..17.57
rows=1 width=33)
Jul 1 06:44:25 zyklon postgres[25053]: [20-18]
Index Cond: (t.evidid = (d.rowid2)::bigint)
Jul 1 06:44:25 zyklon postgres[25053]: [20-19] STATEMENT:
Jul 1 06:44:25 zyklon postgres[25053]: [20-20]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",
Jul 1 06:44:25 zyklon postgres[25053]: [20-21]
t.id ,a_session
Jul 1 06:44:25 zyklon postgres[25053]: [20-22]
FROM bucardo.bucardo_delta d
Jul 1 06:44:25 zyklon postgres[25053]: [20-23] LEFT
JOIN public.sessions t ON (t.id::bpchar = d.rowid::bpchar)
Jul 1 06:44:25 zyklon postgres[25053]: [20-24]
WHERE d.tablename = 9830383::oid
Jul 1 06:44:25 zyklon postgres[25053]: [20-25]
AND NOT EXISTS (
Jul 1 06:44:25 zyklon postgres[25053]: [20-26]
SELECT 1
Jul 1 06:44:25 zyklon postgres[25053]: [20-27]
FROM bucardo.bucardo_track bt
Jul 1 06:44:25 zyklon postgres[25053]: [20-28]
WHERE d.txntime = bt.txntime
Jul 1 06:44:25 zyklon postgres[25053]: [20-29]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:44:25 zyklon postgres[25053]: [20-30]
AND bt.tablename = 9830383::oid
Jul 1 06:44:25 zyklon postgres[25053]: [20-31]
)
Jul 1 06:44:25 zyklon postgres[25053]: [20-32]
Jul 1 06:45:40 zyklon postgres[25053]: [21-1] LOG: duration: 49752.753
ms execute dbdpg_p48255_42:
Jul 1 06:45:40 zyklon postgres[25053]: [21-2]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",
Jul 1 06:45:40 zyklon postgres[25053]: [21-3]
t.id ,netblock,type,exported,action,ts
Jul 1 06:45:40 zyklon postgres[25053]: [21-4]
FROM bucardo.bucardo_delta d
Jul 1 06:45:40 zyklon postgres[25053]: [21-5] LEFT
JOIN public.changes t ON (t.id::int8 = d.rowid::int8)
Jul 1 06:45:40 zyklon postgres[25053]: [21-6]
WHERE d.tablename = 14804208::oid
Jul 1 06:45:40 zyklon postgres[25053]: [21-7]
AND NOT EXISTS (
Jul 1 06:45:40 zyklon postgres[25053]: [21-8]
SELECT 1
Jul 1 06:45:40 zyklon postgres[25053]: [21-9]
FROM bucardo.bucardo_track bt
Jul 1 06:45:40 zyklon postgres[25053]: [21-10]
WHERE d.txntime = bt.txntime
Jul 1 06:45:40 zyklon postgres[25053]: [21-11]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:45:40 zyklon postgres[25053]: [21-12]
AND bt.tablename = 14804208::oid
Jul 1 06:45:40 zyklon postgres[25053]: [21-13]
)
Jul 1 06:45:40 zyklon postgres[25053]: [21-14]
Jul 1 06:45:44 zyklon postgres[25053]: [22-1] LOG: duration: 49752.731
ms plan:
Jul 1 06:45:44 zyklon postgres[25053]: [22-2] Unique
(cost=104440.76..104440.78 rows=1 width=43)
Jul 1 06:45:44 zyklon postgres[25053]: [22-3] -> Sort
(cost=104440.76..104440.76 rows=1 width=43)
Jul 1 06:45:44 zyklon postgres[25053]: [22-4] Sort Key:
d.rowid, t.id, t.netblock, t.type, t.exported, t.action, t.ts
Jul 1 06:45:44 zyklon postgres[25053]: [22-5] -> Nested
Loop Left Join (cost=68267.25..104440.75 rows=1 width=43)
Jul 1 06:45:44 zyklon postgres[25053]: [22-6] ->
Merge Anti Join (cost=68267.25..104434.01 rows=1 width=8)
Jul 1 06:45:44 zyklon postgres[25053]: [22-7]
Merge Cond: (d.txntime = bt.txntime)
Jul 1 06:45:44 zyklon postgres[25053]: [22-8]
-> Index Scan using bucardo_delta_public_changes_txn on bucardo_delta
d (cost=0.00..25654.58 rows=190886 width=16)
Jul 1 06:45:44 zyklon postgres[25053]: [22-9]
-> Sort (cost=68267.15..68744.87 rows=191086 width=8)
Jul 1 06:45:44 zyklon postgres[25053]: [22-10]
Sort Key: bt.txntime
Jul 1 06:45:44 zyklon postgres[25053]: [22-11]
-> Bitmap Heap Scan on bucardo_track bt
(cost=9088.19..51505.22 rows=191086 width=8)
Jul 1 06:45:44 zyklon postgres[25053]: [22-12]
Recheck Cond: ((tablename =
14804208::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:45:44 zyklon postgres[25053]: [22-13]
-> Bitmap Index Scan on
bucardo_track_target (cost=0.00..9040.42 rows=191086 width=0)
Jul 1 06:45:44 zyklon postgres[25053]: [22-14]
Index Cond: ((tablename =
14804208::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:45:44 zyklon postgres[25053]: [22-15] ->
Index Scan using changes_pkey on changes t (cost=0.00..6.62 rows=1
width=35)
Jul 1 06:45:44 zyklon postgres[25053]: [22-16]
Index Cond: (t.id = (d.rowid)::bigint)
Jul 1 06:45:44 zyklon postgres[25053]: [22-17] STATEMENT:
Jul 1 06:45:44 zyklon postgres[25053]: [22-18]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",
Jul 1 06:45:44 zyklon postgres[25053]: [22-19]
t.id ,hostname,type,exported,action,ts
Jul 1 06:45:44 zyklon postgres[25053]: [22-20]
FROM bucardo.bucardo_delta d
Jul 1 06:45:44 zyklon postgres[25053]: [22-21] LEFT
JOIN public.hostchanges t ON (t.id::int8 = d.rowid::int8)
Jul 1 06:45:44 zyklon postgres[25053]: [22-22]
WHERE d.tablename = 14879660::oid
Jul 1 06:45:44 zyklon postgres[25053]: [22-23]
AND NOT EXISTS (
Jul 1 06:45:44 zyklon postgres[25053]: [22-24]
SELECT 1
Jul 1 06:45:44 zyklon postgres[25053]: [22-25]
FROM bucardo.bucardo_track bt
Jul 1 06:45:44 zyklon postgres[25053]: [22-26]
WHERE d.txntime = bt.txntime
Jul 1 06:45:44 zyklon postgres[25053]: [22-27]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:45:44 zyklon postgres[25053]: [22-28]
AND bt.tablename = 14879660::oid
Jul 1 06:45:44 zyklon postgres[25053]: [22-29]
)
Jul 1 06:45:44 zyklon postgres[25053]: [22-30]
Jul 1 06:46:49 zyklon postgres[25053]: [23-1] LOG: duration: 64778.189
ms execute dbdpg_p48255_43:
Jul 1 06:46:49 zyklon postgres[25053]: [23-2]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",
Jul 1 06:46:49 zyklon postgres[25053]: [23-3]
t.id ,hostname,type,exported,action,ts
Jul 1 06:46:49 zyklon postgres[25053]: [23-4]
FROM bucardo.bucardo_delta d
Jul 1 06:46:49 zyklon postgres[25053]: [23-5] LEFT
JOIN public.hostchanges t ON (t.id::int8 = d.rowid::int8)
Jul 1 06:46:49 zyklon postgres[25053]: [23-6]
WHERE d.tablename = 14879660::oid
Jul 1 06:46:49 zyklon postgres[25053]: [23-7]
AND NOT EXISTS (
Jul 1 06:46:49 zyklon postgres[25053]: [23-8]
SELECT 1
Jul 1 06:46:49 zyklon postgres[25053]: [23-9]
FROM bucardo.bucardo_track bt
Jul 1 06:46:49 zyklon postgres[25053]: [23-10]
WHERE d.txntime = bt.txntime
Jul 1 06:46:49 zyklon postgres[25053]: [23-11]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:46:49 zyklon postgres[25053]: [23-12]
AND bt.tablename = 14879660::oid
Jul 1 06:46:49 zyklon postgres[25053]: [23-13]
)
Jul 1 06:46:49 zyklon postgres[25053]: [23-14]
Jul 1 06:46:52 zyklon postgres[25053]: [24-1] LOG: duration: 64778.164
ms plan:
Jul 1 06:46:52 zyklon postgres[25053]: [24-2] Unique
(cost=161176.43..161176.45 rows=1 width=53)
Jul 1 06:46:52 zyklon postgres[25053]: [24-3] -> Sort
(cost=161176.43..161176.43 rows=1 width=53)
Jul 1 06:46:52 zyklon postgres[25053]: [24-4] Sort Key:
d.rowid, t.id, t.hostname, t.type, t.exported, t.action, t.ts
Jul 1 06:46:52 zyklon postgres[25053]: [24-5] -> Nested
Loop Left Join (cost=59965.13..161176.42 rows=1 width=53)
Jul 1 06:46:52 zyklon postgres[25053]: [24-6] ->
Merge Anti Join (cost=59965.12..161169.38 rows=1 width=8)
Jul 1 06:46:52 zyklon postgres[25053]: [24-7]
Merge Cond: (d.txntime = bt.txntime)
Jul 1 06:46:52 zyklon postgres[25053]: [24-8]
-> Index Scan using bucardo_delta_public_hostchanges_txn on
bucardo_delta d (cost=0.00..76303.62 rows=570286 width=16)
Jul 1 06:46:52 zyklon postgres[25053]: [24-9]
-> Sort (cost=59965.01..60358.65 rows=157454 width=8)
Jul 1 06:46:52 zyklon postgres[25053]: [24-10]
Sort Key: bt.txntime
Jul 1 06:46:52 zyklon postgres[25053]: [24-11]
-> Bitmap Heap Scan on bucardo_track bt
(cost=7487.46..46373.13 rows=157454 width=8)
Jul 1 06:46:52 zyklon postgres[25053]: [24-12]
Recheck Cond: ((tablename =
14879660::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:46:52 zyklon postgres[25053]: [24-13]
-> Bitmap Index Scan on
bucardo_track_target (cost=0.00..7448.10 rows=157454 width=0)
Jul 1 06:46:52 zyklon postgres[25053]: [24-14]
Index Cond: ((tablename =
14879660::oid) AND (targetdb = 'usmaster'::text))
Jul 1 06:46:52 zyklon postgres[25053]: [24-15] ->
Index Scan using hostchanges_pkey on hostchanges t (cost=0.00..6.93
rows=1 width=45)
Jul 1 06:46:52 zyklon postgres[25053]: [24-16]
Index Cond: (t.id = (d.rowid)::bigint)
Jul 1 06:46:52 zyklon postgres[25053]: [24-17] STATEMENT:
Jul 1 06:46:52 zyklon postgres[25053]: [24-18]
SELECT DISTINCT d.rowid AS "BUCARDO_ID",d.rowid2 AS
"BUCARDO_ID2",d.rowid3 AS "BUCARDO_ID3",
Jul 1 06:46:52 zyklon postgres[25053]: [24-19]
t.sid,t.emailid,t.assigned ,expired
Jul 1 06:46:52 zyklon postgres[25053]: [24-20]
FROM bucardo.bucardo_delta d
Jul 1 06:46:52 zyklon postgres[25053]: [24-21] LEFT
JOIN public.account2email t ON (t.sid::int8 = d.rowid::int8 AND
t.emailid::int8 = d.rowid2::int8 AND t.assigned::timestamptz =
d.rowid3::timestamptz)
Jul 1 06:46:52 zyklon postgres[25053]: [24-22]
WHERE d.tablename = 9830227::oid
Jul 1 06:46:52 zyklon postgres[25053]: [24-23]
AND NOT EXISTS (
Jul 1 06:46:52 zyklon postgres[25053]: [24-24]
SELECT 1
Jul 1 06:46:52 zyklon postgres[25053]: [24-25]
FROM bucardo.bucardo_track bt
Jul 1 06:46:52 zyklon postgres[25053]: [24-26]
WHERE d.txntime = bt.txntime
Jul 1 06:46:52 zyklon postgres[25053]: [24-27]
AND bt.targetdb = 'usmaster'::text
Jul 1 06:46:52 zyklon postgres[25053]: [24-28]
AND bt.tablename = 9830227::oid
Jul 1 06:46:52 zyklon postgres[25053]: [24-29]
)
Jul 1 06:46:52 zyklon postgres[25053]: [24-30]
> The inserts will be different, but should not be *that* different. A
> swap sync may have updates, but a pushdelta sync never will, it will
> simply have deletes plus inserts (which covers deletes, updates, and
> inserts). In this case, it deleted 2262 rows, although it may have
> requested many more (via DELETE FROM foo WHERE pk IN (1,2,3...))
> If you can narrow it to a smaller test case, that would help see
> what is going on (perhaps creating separate syncs with a single
> table?)
>
>
That'd be fairly impossible at this stage (I'm already 3 months late on
this project hopefully it will be released in about a week or 2 then
will be able to debug more... )
Shells
More information about the Bucardo-general
mailing list