Re: High number of created consistent read blocks when inserting into a LOB column from dblink

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_at_gmail.com> 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_at_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_at_loopback, t_rn_at_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
>

--
http://www.freelists.org/webpage/oracle-l