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

  • From: Mladen Gogala <gogala.mladen@xxxxxxxxx>
  • To: oracle-l@xxxxxxxxxxxxx
  • Date: Thu, 22 Dec 2016 15:20:23 -0500

Sayan, when LOB columns have "cache" attribute turned on, they tend to flood the SGA and just transfer IO's to other tables. The solution is not to use Oracle for LOB columns. I usually put LOBs into MongoDB and index them with Sphinx. Oracle is, simply put, a disaster when it comes to LOB documents. Oracle is like a BMW 850: excellent car, but not well suited for transporting 40 tons of bricks from Scranton to Brooklyn.

Have a merry Christmas/Festivus and a New Year.


On 12/21/2016 12:17 PM, Sayan Malakshinov wrote:

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 <mailto: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 <http://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 <http://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



--
Mladen Gogala
Oracle DBA
http://mgogala.freehostia.com

Other related posts: