Hi Jure,
Have you tried to enable "cache"?
Ps. It helped me once for huge parallel load (as far as I remember it
helped to reduce concurrency for control file)
Best regards,
Sayan Malakshinov
http://orasql.org
On Dec 21, 2016 20:02, "Jure Bratina" <jure.bratina@xxxxxxxxx> wrote:
Hi,
I'm experiencing a high number of consistent gets when reading data from a
dblink and inserting it into a local table with a LOB column, and thought
to ask if anyone else has experienced that or has any comment about that
behaviour. I'm on 12.1.0.2 Linux x86-64.
There are actually some bugs reported with similar, but not same, symptoms
(e.g. "Bug 20555404 : INSERT VIA DBLINK SLOW AFTER UPGRADE TO 11.2.0.4" or
"Bug 13641076 : HIGH AMOUNT OF BUFFER GETS FOR INSERT STATEMENT - REJECTION
LIST DOES NOT FIRE"), however not for 12.1.
Brief description: When performing an "insert /*+append*/ into .. select
from table@dblink" and data insertion progresses, the CPU usage of the
session gradually increases to 90% of the session's activity, as does the
number of consistent reads, particularly the statistic "CR blocks created"
(7,36k/second) and, by a similar figure, the statistic "consistent gets
examination". Interestingly there's no change in "data blocks consistent
reads - undo records applied". So it seems the session is consuming most
of its time creating consistent read copies of blocks by reading and
applying undo blocks. What's also interesting is "transaction rollbacks"
is approx 1/second.
There's also a sustainable number of gets on the "lob segment dispenser
latch" latch and quite some undo generated (more details below), even
though I'm doing a direct path insert. Checking some of UNDO blocks' dump,
the content is mostly about space management of LOB chunks, e.g.:
KTSL - LOB Persistent Undo Block (PUB) undo record:
bdba: 0x0180168b class: 10
KTSL - PUA redo record:
1: On disk rollback of 1 chunks
On disk rollback: mark chunk free: 0x18f110b
Also, the object in v$bh that has the most blocks in 'cr' mode is the LOB
segment (not LOB index).
Problem reproduction, using the default USERS tablespace (locally managed,
ASSM):
create table t1(
id number,
c1 clob
)
lob (c1)
store as securefile
(
disable storage in row
chunk 8k
retention
nocache
tablespace users
)
tablespace users
;
Then create table "t2" with exactly the same properties and structure as
t1. Next, create some sample data:
declare
c clob;
begin
for i in 1..200 loop
insert into t1 values (i, empty_clob() )
returning c1 into c;
for j in 1 .. i loop
dbms_lob.writeappend(c,2048,rpad(to_char(i),2048,'x'));
end loop;
end loop;
commit;
end;
/
And a dummy table, to avoid using any expressions, like ROWNUM, in the
remote statement, and to have a "clean" remote SQL:
SQL> create table t_rn as select rownum rn from dual connect by level <=
100;
Then using a loopback database link (connecting to the same user on the
same database) I execute the INSERT:
SQL> insert /*+append*/ into t2 (id, c1)
2 select id, c1 from t1@loopback, t_rn@loopback
3 where t1.id >= 0;
Because of the length of the mail, I'll try to report just the session
statistics, latches and enqueues I think are relevant. I'll also spare you
the statistics from the actual system where I encountered the issue.
Figures are deltas per second:
-------------------------------------------------------------
TYPE, STATISTIC , HDELTA/SEC
-------------------------------------------------------------
ENQG, DX - Distributed Transaction , 159,06
ENQG, TX - Transaction , 1,36k
LATG, lob segment dispenser latch , 11,76k
STAT, session logical reads , 297,32k
STAT, db block gets , 293,13k
STAT, consistent gets , 4,19k
STAT, consistent gets examination , 466,53
STAT, db block changes , 4,99k
STAT, consistent changes , 481,36
STAT, CR blocks created , 481,69
STAT, transaction rollbacks , 1,11
STAT, commit batch/immediate performed , 1,15
STAT, segment dispenser allocations , 650,29
STAT, segment chunks allocation from disepnser , 654,43
STAT, KTFB alloc space (block) , 222,55k
----------------------------------------------------------------------
ActSes %Thread | SQL_ID | SQL_CHILD | EVENT
----------------------------------------------------------------------
.60 (60%) | akbww745v7jav | 0 | direct path write
.32 (32%) | akbww745v7jav | 0 | ON CPU
SQL> select used_ublk, used_urec, log_io, phy_io, cr_get, cr_change from
v$transaction;
USED_UBLK USED_UREC LOG_IO PHY_IO CR_GET CR_CHANGE
---------- ---------- ---------- ---------- ---------- ----------
3990 247241 113280741 1031760 1589403 191702
Contrast that with a locally executed INSERT, after recreating t2:
SQL> insert /*+append*/ into t2 (id, c1)
2 select id, c1 from t1, t_rn
3 where t1.id >= 0;
-------------------------------------------------------------
TYPE, STATISTIC , HDELTA/SEC
-------------------------------------------------------------
ENQG, TX - Transaction , 74,85
LATG, lob segment dispenser latch , 478,27
STAT, session logical reads , 2,18k
STAT, db block gets , 543,15
STAT, consistent gets , 1,64k
STAT, consistent gets examination , 1,59k
STAT, db block changes , 178,52
STAT, consistent changes , 4,05
STAT, CR blocks created , 4,05
STAT, transaction rollbacks , ,06
STAT, commit batch/immediate performed , ,32
STAT, segment dispenser allocations , 27,65
STAT, segment chunks allocation from disepnser , 27,65
STAT, KTFB alloc space (block) , 104,2k
--------------------------------------------------------------------
ActSes %Thread | SQL_ID | SQL_CHILD | EVENT
--------------------------------------------------------------------
.87 (87%) | 9ydka790v3qh3 | 0 | direct path write
.13 (13%) | 9ydka790v3qh3 | 0 | ON CPU
SQL> select used_ublk, used_urec, log_io, phy_io, cr_get, cr_change from
v$transaction;
USED_UBLK USED_UREC LOG_IO PHY_IO CR_GET CR_CHANGE
---------- ---------- ---------- ---------- ---------- ----------
29 1723 44718 2063335 101146 252
Tracing with events 10200 and 10201 shows there's some activity on blocks
related to the data dictionary objects (LINK$, IDL_UB1$) although from the
number of entries I'm not sure how reliable this trace is (or me analyzing
it). Considering all above, it seems there's some LOB space management
activity going on and it also seems, based on the statistic "transaction
rollbacks" and "commit batch/immediate performed", there are some kind of
recursive/autonomous transactions going on, although I didn't notice them
in the 10046 trace (no XCTEND lines). Maybe they are performed by some
other space management background process, although if that's so, I'm not
sure why would they be reported in this session's statistics.
A possible workaround seems to be to perform the insert from a PL/SQL loop
and commit in between inserts, however I still have to check that approach.
Any thoughts on how to find out the root cause of that behaviour?
Thank you in advance and regards,
Jure Bratina
