Search

Top 60 Oracle Blogs

Recent comments

Oakies Blog Aggregator

TKPROF’s Argument PDBTRACE

If you run TKPROF without arguments, you get a complete list of its arguments with a short description for each of them (here the output generated by version 18.1.0):

$ tkprof
Usage: tkprof tracefile outputfile [explain= ] [table= ]
              [print= ] [insert= ] [sys= ] [sort= ]
  table=schema.tablename   Use 'schema.tablename' with 'explain=' option.
  explain=user/password    Connect to ORACLE and issue EXPLAIN PLAN.
  print=integer    List only the first 'integer' SQL statements.
  pdbtrace=user/password   Connect to ORACLE to retrieve SQL trace records.
  aggregate=yes|no
  insert=filename  List SQL statements and data inside INSERT statements.
  sys=no           TKPROF does not list SQL statements run as user SYS.
  record=filename  Record non-recursive statements found in the trace file.
  waits=yes|no     Record summary for any wait events found in the trace file.
  sort=option      Set of zero or more of the following sort options:
    prscnt  number of times parse was called
    prscpu  cpu time parsing
    prsela  elapsed time parsing
    prsdsk  number of disk reads during parse
    prsqry  number of buffers for consistent read during parse
    prscu   number of buffers for current read during parse
    prsmis  number of misses in library cache during parse
    execnt  number of execute was called
    execpu  cpu time spent executing
    exeela  elapsed time executing
    exedsk  number of disk reads during execute
    exeqry  number of buffers for consistent read during execute
    execu   number of buffers for current read during execute
    exerow  number of rows processed during execute
    exemis  number of library cache misses during execute
    fchcnt  number of times fetch was called
    fchcpu  cpu time spent fetching
    fchela  elapsed time fetching
    fchdsk  number of disk reads during fetch
    fchqry  number of buffers for consistent read during fetch
    fchcu   number of buffers for current read during fetch
    fchrow  number of rows fetched
    userid  userid of user that parsed the cursor

If you carefully check the output, you can notice an argument that does exist only from version 12.2 onward: “pdbtrace”. If I correctly remember, since the introduction of TKPROF in Oracle7, only another time Oracle added a new argument. It was “waits” in Oracle9. Interestingly, the documentation provides no information about it.

So, the question is: what does the new argument do?

Since its name contains “pdb”, one might think that it is related to Multitenant. But, after a number of tests, it does not seem to be related to it. Simply put, “pdbtrace” can be used to process a trace file without requiring direct access to the OS where the trace file is stored. Instead, when “pdbtrace” is specified, the trace file is read through one of the dynamic performance views introduced in version 12.2 to access them (e.g. V$DIAG_TRACE_FILE and V$DIAG_TRACE_FILE_CONTENTS; have a look to this post for some basic information about them).

For example, the following command instructs TKPROF to connect a database instance with the specified user and password, to read the input file DBM1810S_ora_18264.trc, and produce the output file DBM1810S_ora_18264.txt locally.

$ tkprof DBM1810S_ora_18264.trc DBM1810S_ora_18264.txt pdbtrace=chris/secret@pdb1

All in all, except for the name, a good addition to TKPROF.

Addenda 2018-03-22

Be careful that when the “pdbtrace” argument is specified, the input trace file can’t specify the directory where the trace file is located. If a directory name or a non-existent trace file is specified, no interactive error message is shown. Instead, an empty output file is generated. Similarly, if an invalid user, password, or connect string is specified, an empty output file is generated without any interactive error message. Instead, an error like the following will be found in the output file just before the header:

error connecting to database using: scott/lion
ORA-01017: invalid username/password; logon denied

Trip down memory lane

I did a little video for St Patricks day, but it also brought back memories of my first computer experiences.  A Sinclair ZX80, a Commodore 64, and many other machines that I thought were so cool for their time.

Feel free to share your experiences in comments.

Announcement: Europe June 2018 Dates – Oracle Indexing Internals Seminar

I’m very excited to announce some European June 2018 dates for my popular “Oracle Indexing Internals and Best Practices” seminar. This is a must attend seminar of benefit to not only DBAs, but also to Developers, Solution Architects and anyone else interested in designing, developing or maintaining high performance Oracle-based applications. It’s a fun, but […]

Resetting High Water Marks on On-line Temporary Table Instances

PeopleSoft has always used regular database tables for temporary working storage in batch processes.   Up to PeopleTools 7.x working storage tables were shared by all instances of a program.  That led to consistent read contention when multiple processes concurrently used the same table, and much higher high water marks that increased durations of full scans.
From PeopleTools 8, many copies of each temporary working storage table are created.  Application Engines that run on the Process Scheduler are allocated exclusive use of a particular copy of the table.  This avoids the inter-process contention.  They start by truncating each allocated table, which resets the high-water mark.
Some delivered processing uses batch programs that are run apparently synchronously from the PIA.  On-line edit and post in Financials General Ledger is a common example.  Up to PeopleTools 7, the application server would synchronously spawn a batch process and wait for it to complete.  From PeopleTools 8 the process is submitted to the process scheduler, and the PIA polls the Scheduler tables waiting for the process to complete.  However, Application Engine can be run within the component processor.  In Financials General Ledger, this can be chosen by a setting an installation configuration option.  The truly on-line method can perform better because you are no longer waiting for the process scheduler to pick up the process request.  A separate process Application Engine is not spawned, but the Application Engine program is executed by the PSAPPSRV application server process.  One of the limitations is that the Application Engine program cannot commit.  Committing after steps or sections is suppressed, and the %TruncateTable macro generates a delete statement instead.  Therefore, on-line temporary table instances are never truncated by any process and their high-water marks can be raised by processes that handle larger volumes of data.  This can have impacts for subsequent processes with smaller data volumes but that still have to full-scan working storage tables up to their high water marks.

Truncating On-line Temporary Table Instances

The answer is to implement a periodic process that truncates working storage tables, but only doing so when the table is not currently being used by a process.  Every on-line Application Engine program is allocated a temporary table instance number, it locks the corresponding row on the table PS_AEONLINEINST.  If it allocated to instance 1, it locks the row where CURTEMPINSTANCE is 1 and uses instance 1 of each temporary record that it needs.  
Therefore the proposed truncate process must also lock the row on PS_AEONLINEINST that corresponds to each table that is to be truncated.  The truncate must be done in an autonomous transaction so that the implicit commit does not release that lock.  The lock can be released after the truncate completes.  Thus, the truncate process waits for any online process to complete before truncating a table with the same instance number, and no process can start while the truncate process is holding the lock.  However, each truncate will be very quick, and so each lock will only be held briefly, and it will have only a minimal effect on any online process that may be running at the time.  
I have written a PL/SQL packaged procedure (to perform this process for all temporary records.  It is available on Github as a part of my collection of miscellaneous PeopleSoft scripts.

Package Usage

Usually, the package will be run without any parameters. The default behaviour will be to truncate tables with more than a single extent.  Information on what the package does is emitted to the server output.

#eeeeee; border: 0px solid #000000; font-family: courier new; font-size: 100%; overflow: auto; padding-left: 4px; padding-right: 4px; width: 95%;">Set serveroutput on 
EXECUTE xx_onlineinsthwmreset.main;

The package can be run in test mode when it will list the commands without executing them.  Thus you can see what it will do without actually doing it.

#eeeeee; border: 0px solid #000000; font-family: courier new; font-size: 100%; overflow: auto; padding-left: 4px; padding-right: 4px; width: 95%;">EXECUTE xx_onlineinsthwmreset.main(p_testmode=>TRUE);

The package can optionally deallocate any physical storage. Storage will be reallocated next time the table is used.

#eeeeee; border: 0px solid #000000; font-family: courier new; font-size: 100%; overflow: auto; padding-left: 4px; padding-right: 4px; width: 95%;">EXECUTE xx_onlineinsthwmreset.main(p_drop_storage=>TRUE, p_min_extents=>0);

The package can be run for certain tables that match a particular pattern.

#eeeeee; border: 0px solid #000000; font-family: courier new; font-size: 100%; overflow: auto; padding-left: 4px; padding-right: 4px; width: 95%;">EXECUTE xx_onlineinsthwmreset.main(p_recname_like=>'JP%');

I recommend that the package is run daily. However, it can be run safely while the users are doing on-line edit/post processing, but it would be sensible to choose a quiet time.

Presenting At ODTUG Kscope18 Conference in Orlando, Florida 10-14 June 2018

I’m very excited to have a couple of papers accepted at this year’s ODTUG Kscope18 Conference in sunny and likely very hot Orlando, Florida between 10-14 June 2018. I’m excited because I’ve been to a few of these conferences before and they have always been excellent events. As a mainly Oracle Database kinda guy, it’s […]

A look into oracle redo, part 7: adaptive log file sync

This is the seventh part of a blog series about oracle redo.

Adaptive log file sync is a feature that probably came with Oracle version 11.2. Probably means I looked at the undocumented parameters of Oracle version 11.1 and do not see any of the ‘_adaptive_log_file_sync*’ parameters. It was actually turned off by default with versions 11.2.0.1 and 11.2.0.2, and was turned on by default since version 11.2.0.3.

The adaptive log file sync feature means the logwriter can make the committing sessions switch from the traditional post/wait mechanism for redo write notification to a mechanism where the committing session picks a time to sleep after which it checks for the redo writing progress itself. The reasons for doing so that I can see are reducing the amount of work the logwriter needs to do, because semop’ing a semaphore can only be done serially, and prevent the logwriter process from the situation of getting scheduled off CPU because the processes it’s activating via semop are getting higher priorities than the logwriter.

An important thing to realise is that the adaptive log file sync mechanism only potentially can change a single communication event in the database, which is when a session needs to wait for its redo to be written to disk by the logwriter after a commit. Nothing else is changed and all other post/wait inter-process communication is done exactly the same.

Is this feature a good idea? In part 6 of my Oracle redo series I have shown that a process is checking the on-disk SCN even if the log file sync method is post/wait, but it needs to be posted before it will continue. I have seen cases where huge numbers of foreground processes were doing lots of commits per second, especially in these cases I can see how the logwriter can greatly benefit from not having to do a lot of semop calls after writing, and thus not spend its time on what the logwriter actually should be doing, which is writing. I have not seen any great benefits in databases where there’s a low redo writing and commit rate.

But how does this feature work? In order to investigate that I first executed a pinatrace on a sysdba session and executed:

SQL> alter system set "_use_adaptive_log_file_sync" = false scope = memory;

Then used my pinatrace annotate script to annotate the pinatrace output, and simply grepped for ‘kcrf’; I highly suspect the adaptive log file sync feature to be a ‘kernel cache redo file’ (kcrf) based feature:

$ grep kcrf pinatrace_17029_ann.txt
11452:kcrf_sync_adaptive_set+2:0x00007ffef43aecd0():W:8:0x7ffef43af1b0/140732995924400()
11453:kcrf_sync_adaptive_set+10:0x00007ffef43aecb0():W:8:0x7f703fa2ef40/140120080707392()
11454:kcrf_sync_adaptive_set+17:0x00007ffef43aecb8():W:8:0x115b3da0/291192224()
11455:kcrf_sync_adaptive_set+37:0x00007ffef43aecc0():W:8:0x7ffef43aefe8/140732995923944()
11456:kcrf_sync_adaptive_set+44:0x00007ffef43aecc8():W:8:0x7f703f9ec9a0/140120080435616()
11457:kcrf_sync_adaptive_set+48:0x00007ffef43aeca8():W:8:0xcf7c7f5/217565173()
11506:kcrf_sync_adaptive_set+81:0x00007ffef43aeca8():W:8:0xcf7c816/217565206()
11555:kcrf_sync_adaptive_set+100:0x0000000060016a34(Fixed Size(pgsz:2048k)|+92724 fixed sga|var:kcrf_sync_sleep_usecs_+0 shared pool|(indx:0)X$KSXRSG+49636 ):R:4:0/0()
11556:kcrf_sync_adaptive_set+161:0x0000000060016a38(Fixed Size(pgsz:2048k)|+92728 fixed sga|var:kcrf_alfs_info_+0 shared pool|(indx:0)X$KSXRSG+49640 ):W:4:0/0()
11557:kcrf_sync_adaptive_set+202:0x0000000060016a40(Fixed Size(pgsz:2048k)|+92736 fixed sga|var:kcrf_alfs_info_+8 shared pool|(indx:0)X$KSXRSG+49648 ):W:4:0/0()
11558:kcrf_sync_adaptive_set+352:0x00007ffef43aecc8():R:8:0x7f703f9ec9a0/140120080435616()
11559:kcrf_sync_adaptive_set+356:0x00007ffef43aecc0():R:8:0x7ffef43aefe8/140732995923944()
11560:kcrf_sync_adaptive_set+360:0x00007ffef43aecb8():R:8:0x115b3da0/291192224()
11561:kcrf_sync_adaptive_set+364:0x00007ffef43aecb0():R:8:0x7f703fa2ef40/140120080707392()
11562:kcrf_sync_adaptive_set+371:0x00007ffef43aecd0():R:8:0x7ffef43af1b0/140732995924400()
11563:kcrf_sync_adaptive_set+372:0x00007ffef43aecd8():R:8:0x1034e7e/16993918()
77244:kzam_check_limit+342:0x0000000060016398(Fixed Size(pgsz:2048k)|+91032 fixed sga|var:kcrfsg_+368 shared pool|(indx:0)X$KSXRSG+47944 ):R:4:0xd3/211()

If the feature is set/changed (the database was in adaptive log file sync mode, because “_use_adaptive_log_file_sync” was not set), it must write in a shared memory location for the other processes to be able to see the setting. That means two things: 1) any non-shared memory location can not be relevant to the setting, so we can exclude these 2) in order to change something, there needs to be a WRITE to set it.

To make the investigation easier to do, I added an option to the annotate script to write the pinatrace_annotate output to a sqlite3 database. In order to do this, use the ‘-d’ (database) switch to the pinatrace_annotate.sh script.

First we need to know the max SGA address of the instance, this can be found in the memory_ranges.db sqlite database, which is created when the memory details are prepared using ‘./pinatrace_annotate.sh -c’:

$ sqlite3 memory_ranges.db
SQLite version 3.21.0 2017-10-24 18:55:49
Enter ".help" for usage hints.
sqlite> select printf('%x',max(end_address)) from memory_ranges;
e0000000

(please mind you need an sqlite3 version higher than 3.7 (which comes with Oracle Linux) to use printf. I downloaded the latest version from https://www.sqlite.org/download.html)

Okay so anything higher than 0xe0000000 is not in the SGA. Now use the database that was created using the ‘-d’ switch when I annotated the pinatrace output of ‘alter system set “_use_adaptive_log_file_sync” = false scope = memory’:

$ sqlite3 pinatrace_17029.txt.db
SQLite version 3.21.0 2017-10-24 18:55:49
Enter ".help" for usage hints.
sqlite> select line, function_offset, printf('%x',memory_address), memory_annotation, read_write, size, value, value_annotation from annotation where memory_annotation like '%kcrf%' and memory_address <= printf('%d',0xe0000000) and read_write = 'W';
11556|kcrf_sync_adaptive_set+161|60016a38|Fixed Size(pgsz:2048k)|+92728 fixed sga|var:kcrf_alfs_info_+0 shared pool|(indx:0)X$KSXRSG+49640 |W|4|0|??
11557|kcrf_sync_adaptive_set+202|60016a40|Fixed Size(pgsz:2048k)|+92736 fixed sga|var:kcrf_alfs_info_+8 shared pool|(indx:0)X$KSXRSG+49648 |W|4|0|??

This means that when I execute the alter system command, something is written into the fixed SGA, into a variable called ‘kcrf_alfs_info_’. I am pretty sure ‘alfs’ means adaptive log file sync here (and not many occasions of Gordon Shumway). There is a zero written in a 4 byte memory location at kcrf_alfs_info_+0, and there’s a zero written at kcrf_alfs_info_+8.

Now let’s repeat this, but with the pinatrace output when executing ‘alter system set “_use_adaptive_log_file_sync” = true scope = memory’:

$ sqlite3 pinatrace_8204.txt.db
SQLite version 3.21.0 2017-10-24 18:55:49
Enter ".help" for usage hints.
sqlite> select line, function_offset, printf('%x',memory_address), memory_annotation, read_write, size, value, value_annotation from annotation where memory_annotation like '%kcrf%' and memory_address <= printf('%d',0xe0000000) and read_write = 'W';
82476|kcrf_sync_adaptive_set+161|60016a38|Fixed Size(pgsz:2048k)|+92728 fixed sga|var:kcrf_alfs_info_+0 shared pool|(indx:0)X$KSXRSG+49640 |W|4|1|??
82477|kcrf_sync_adaptive_set+202|60016a40|Fixed Size(pgsz:2048k)|+92736 fixed sga|var:kcrf_alfs_info_+8 shared pool|(indx:0)X$KSXRSG+49648 |W|4|0|??

Here the same thing is happening as previously, when it was set to false, with the difference that at kcrf_alfs_info_+0, there is a one written.

Now let’s repeat this again, but with the pinatrace output when executing ‘”_use_adaptive_log_file_sync” = polling_only scope = memory’. This the third value that is allowed for “_use_adaptive_log_file_sync”. In case you are wondering how I knew about this being an allowed parameter value, there’s a script in Tanel Poder’s script bundle that can list them, called pvalid.sql:

SQL> @pvalid adaptive_log_file_sync
Display valid values for multioption parameters matching "adaptive_log_file_sync"...
old  11:   LOWER(NAME_KSPVLD_VALUES) LIKE LOWER('%&1%')
new  11:   LOWER(NAME_KSPVLD_VALUES) LIKE LOWER('%adaptive_log_file_sync%')

  PAR# PARAMETER                                                 ORD VALUE                          DEFAULT
------ -------------------------------------------------- ---------- ------------------------------ -------
  1840 _use_adaptive_log_file_sync                                 1 TRUE                           DEFAULT
       _use_adaptive_log_file_sync                                 2 FALSE
       _use_adaptive_log_file_sync                                 3 POLLING_ONLY

Here is the memory trace of setting “_use_adaptive_log_file_sync” to polling only:

$ sqlite3 pinatrace_25469.txt.db
SQLite version 3.21.0 2017-10-24 18:55:49
Enter ".help" for usage hints.
sqlite> select line, function_offset, printf('%x',memory_address), memory_annotation, read_write, size, value, value_annotation from annotation where memory_annotation like '%kcrf%' and memory_address <= printf('%d',0xe0000000) and read_write = 'W';
94687|kcrf_sync_adaptive_set+161|60016a38|Fixed Size(pgsz:2048k)|+92728 fixed sga|var:kcrf_alfs_info_+0 shared pool|(indx:0)X$KSXRSG+49640 |W|4|1|??
94688|kcrf_sync_adaptive_set+175|60016a40|Fixed Size(pgsz:2048k)|+92736 fixed sga|var:kcrf_alfs_info_+8 shared pool|(indx:0)X$KSXRSG+49648 |W|4|1|??
94689|kcrf_sync_adaptive_set+185|60016a78|Fixed Size(pgsz:2048k)|+92792 fixed sga|var:kcrf_alfs_info_+64 shared pool|(indx:0)X$KSXRSG+49704 |W|4|0|??
94690|kcrf_sync_adaptive_set+191|60016a7c|Fixed Size(pgsz:2048k)|+92796 fixed sga|var:kcrf_alfs_info_+68 shared pool|(indx:0)X$KSXRSG+49708 |W|4|0|??

That’s interesting! Now the values set at offsets 0 and 8 are both one, and there are two additional offsets written to, 64 and 68, to which a zero is written.

It is my interpretation that zero at kcrf_alfs_info_+0 means the adaptive log file sync feature is turned off. In a database starting from version 11.2.0.3 or higher, this can only be the case if the parameter “_use_adaptive_log_file_sync” has been explicitly set to false.

This is a foreground session in a database that where I have set “_use_adaptive_log_file_sync” to false, and performed an insert and commit:

$ grep kcrf_alfs_info_\+[08] insert_ann.txt
72891:kcrf_commit_force_int+268:0x0000000060016a38(Fixed Size(pgsz:2048k)|+92728 fixed sga|var:kcrf_alfs_info_+0 shared pool|(indx:0)X$KSXRSG+49640 ):R:4:0/0()
81847:kcrf_commit_force_int+268:0x0000000060016a38(Fixed Size(pgsz:2048k)|+92728 fixed sga|var:kcrf_alfs_info_+0 shared pool|(indx:0)X$KSXRSG+49640 ):R:4:0/0()
81929:kcrf_commit_force_int+602:0x0000000060016a38(Fixed Size(pgsz:2048k)|+92728 fixed sga|var:kcrf_alfs_info_+0 shared pool|(indx:0)X$KSXRSG+49640 ):R:4:0/0()
81998:kcrf_commit_force_int+1503:0x0000000060016a90(Fixed Size(pgsz:2048k)|+92816 fixed sga|var:kcrf_alfs_info_+88 shared pool|(indx:0)X$KSXRSG+49728 ):R:4:0x3e8/1000()

And this is a foreground session in a database where I removed the parameter “_use_adaptive_log_file_sync”, which means the parameter defaults to true, and executed an insert and commit:

$ grep kcrf_alfs_info_\+[08] pinatrace_2444_ann.txt
71189:kcrf_commit_force_int+268:0x0000000060016a38(Fixed Size(pgsz:2048k)|+92728 fixed sga|var:kcrf_alfs_info_+0 shared pool|(indx:0)X$KSXRSG+49640 ):R:4:0x1/1()
80148:kcrf_commit_force_int+268:0x0000000060016a38(Fixed Size(pgsz:2048k)|+92728 fixed sga|var:kcrf_alfs_info_+0 shared pool|(indx:0)X$KSXRSG+49640 ):R:4:0x1/1()
80230:kcrf_commit_force_int+602:0x0000000060016a38(Fixed Size(pgsz:2048k)|+92728 fixed sga|var:kcrf_alfs_info_+0 shared pool|(indx:0)X$KSXRSG+49640 ):R:4:0x1/1()
80231:kcrf_commit_force_int+615:0x0000000060016a40(Fixed Size(pgsz:2048k)|+92736 fixed sga|var:kcrf_alfs_info_+8 shared pool|(indx:0)X$KSXRSG+49648 ):R:4:0/0()
80254:kcrf_commit_force_int+844:0x0000000060016a90(Fixed Size(pgsz:2048k)|+92816 fixed sga|var:kcrf_alfs_info_+88 shared pool|(indx:0)X$KSXRSG+49728 ):R:4:0x550/1360()

As you can see at row 80230 of the memory trace, the kcrf_commit_force_int function reads kcrf_alfs_info_+0 and finds a one, indicating the adaptive log file sync feature is turned on, and as a result needs to find out if it’s set to post/wait or polling, which is done by looking at kcrf_alfs_info_+8 (row 80231), and finds a zero. The kcrf_commit_force_int execution here is the second stage of the invocation of kcrf_commit_force_int, which is with 1 as second argument, which is when the function performs a wait for the logwriter to write its redo. One way of detecting this usage of kcrf_commit_force_int is by looking at the functions lead to this invocation of kcrf_commit_force_int (ksupop, kcbdsy), because in the pinatrace the function arguments are not visible.

The zero for kcrf_alfs_info_+8 probably means that the adaptive feature still uses post/wait to wait for the logwriter, which is reasonably easy to verify by looking if we see the functions that are associated with the post/wait interface, of which the a few obvious ones are kslawe for setting up the post/wait entry, and another one is a kslgetl/kslfre combination that obtains and frees the ‘post/wait queue’ latch:

79629:kslawe+381:0x0000000060006a60(fixed sga|var:kslpwqs_+0 ):R:8:0x6dd76db0/1842834864(Variable Size(pgsz:2048k)|+219639216 shared pool|(child)latch#1:post/wait queue+0 shared pool|permanent memor,duration 1,cls perm+1322416 )
79630:kslawe+388:0x00007ffcb79aecf0():W:8:0x6dd851b0/1842893232(shared pool|(child)latch#305:post/wait queue+0 shared pool|permanent memor,duration 1,cls perm+1380784 )
79631:kslawe+392:0x00007ffcb79aecd8():W:8:0x10a69edd/279355101()
79632:kslgetl+2:0x00007ffcb79aecd0():W:8:0x7ffcb79aed20/140723388869920()
79633:kslgetl+13:0x00007ffcb79aecb0():W:8:0x132/306()
79634:kslgetl+17:0x00007f303824ff40(??):R:8:0x7f303824ff40/139845077106496(??)
79635:kslgetl+26:0x00007ffcb79aeca8():W:8:0x21/33()
79636:kslgetl+33:0x00007ffcb79aeca0():W:8:0x130/304()
79637:kslgetl+37:0x00007ffcb79aecb8():W:8:0x130/304()
79638:kslgetl+44:0x00007f3038241e78(??):R:8:0x6dde6f10/1843293968(shared pool|(indx:71)X$KSUPR+0 shared pool|permanent memor,duration 1,cls perm+1781520 )
79639:kslgetl+58:0x00007ffcb79aecc0():W:8:0x131/305()
79640:kslgetl+65:0x00007ffcb79aec70():W:8:0x130/304()
79641:kslgetl+69:0x000000006dd851bf(shared pool|(child)latch#305:post/wait queue+15 shared pool|permanent memor,duration 1,cls perm+1380799 ):R:1:0x37/55()
79642:kslgetl+80:0x000000006dde7268(shared pool|(indx:71)X$KSUPR.KSLLALAQ+0 shared pool|permanent memor,duration 1,cls perm+1782376 ):R:8:0/0()

Above we see the a snippet of part of the kslawe function reading the start address of the child latches from the fixed SGA variable kslpwqs_, then kslgetl is called for post/wait queue child latch number 305.

From the previous article we know that a committing session checks the on disk SCN in the kcrfsg_ struct in order to understand if the redo that it put into the public redo strand has been written or not. If the logwriter did not increase the on disk SCN beyond or equal to the commit SCN yet, the committing session loops executing the following functions:
– kslawe: registering itself in the post-wait queue
– kcscu8: check on disk SCN
– kslwaitctx: main waiting routine, semtimedop: wait to be posted for 100ms
– (if not posted) ksliwat_cleanup: remove post-wait entry
– (if not posted) kcscu8: check on disk SCN

Of course when the instance is in adaptive log file sync mode (which any normal database should be nowadays!), it chooses between post-wait and polling, and when post-wait is chosen, the above function sequence is valid, this is independent of being dedicated in post-wait mode or being in post-wait mode because the adaptive log file sync mechanism chose it.

How does this look like when the database in polling mode?
– kcscu8: check on disk SCN
– sltrusleep, nanosleep: wait for a certain amount of time

Yet, it is that simple: all it does is verify the on disk SCN and if it has not progressed equal to or beyond the session’s commit SCN, it sleeps in nanosleep.

The time sleeping in nanosleep as far as I seen, has changed: prior to Oracle version 12.2, the time was calculated dynamically, probably directly or indirectly from the IO time of the logwriter. As far as I can see, in version 12.2 the sleeping time changed to sleeping 1000ns. This sleeping time was the topic of my previous article because a 1000ns/1us sleep seems to be lesser than linux can sleep.

How to use the core functionality of RANDOM_NINJA

In the second video on RANDOM_NINJA I show how to use the core functionality in the 3 main
packages: core_random, text_random and time_random.

How to use the core functionality of RANDOM_NINJA

In the second video on RANDOM_NINJA I show how to use the core functionality in the 3 main
packages: core_random, text_random and time_random.

Reference Costs

The partitioning option “partition by reference” is a very convenient option which keeps acquiring more cute little features, such as cascading truncates and cascading splits, as time passes – but what does it cost and would you use it if you don’t really need to.

When reference partitioning came into existence many years ago, I had already seen several performance disasters created by people’s enthusiasm for surrogate keys and the difficulties this introduced for partition elimination; so my first thought was that this was a mechanism that would have a hugely beneficial effect on systems which (in 20:20 – or 6:6 if you’re European – hindsight) had been badly designed and would otherwise need a lot of re-engineering to use partitioning effectively.

(Side note: Imagine you have partitioned an orders table on colX which is a column in the real (business-oriented) candidate key, but you’ve created a surrogate key which is used as the target for a foreign key from the order_lines tables – how do you get partition-wise joins between orders and order_lines if you haven’t got the partitioning column in the order_lines table ?)

So ref partitioning was a good way to workaround a big existing problem and, whatever overheads it introduced, the benefit was potentially so  huge that you wouldn’t care (or, probably, notice) that your system was less efficient than it ought to be. But what if you’re working on a new project and still have control of the physical design – how does that change the cost/benefit analysis.

It’s actually taken me several years to get round to producing a little demonstration to highlight one of the obvious costs of reference partitioning – even though it’s a very simple demo raising the obvious question: ‘how much work does Oracle have to do to find the right partition when inserting a “child” row ?’ If you chose to implement reference partitioning without asking that simple question you may be using a lot more machine resources than you really need to, although you may not actually be heading for a disastrous performance problem.

As a demonstration of the issue I’m going to set up something that approximates an order/order_lines model in two ways, one using reference partitioning and one using a copied column, to see what differences show up when you start loading data.

rem
rem     Script:         pt_ref.sql
rem     Author:         Jonathan Lewis
rem     Dated:          Mar 2018
rem     Purpose:
rem
rem     Last tested
rem             12.2.0.1
rem             12.1.0.2
rem

create table orders (
        id              number(10,0) not null,
        id_cust         number(10,0) not null,
        date_ordered    date not null,
        padding         varchar2(150)
)
partition by range (date_ordered)
(
        partition p201801       values less than (to_date('01-Feb-2018')),
        partition p201802       values less than (to_date('01-Mar-2018')),
        partition p201803       values less than (to_date('01-Apr-2018')),
        partition p201804       values less than (to_date('01-May-2018')),
        partition p201805       values less than (to_date('01-Jun-2018')),
        partition p201806       values less than (to_date('01-Jul-2018')),
        partition p201807       values less than (to_date('01-Aug-2018'))
);

create unique index ord_pk on orders (id);
alter table orders add constraint ord_pk primary key(id);

create table order_lines (
        id_ord          number(10,0) not null,
        line_number     number(4,0)  not null,
        id_product      number(6,0)  not null,
        qty             number(6,0)  not null,
        value           number(10,2) not null,
        padding         varchar2(150),
        constraint orl_fk_ord foreign key (id_ord) references orders
                on delete cascade
)
partition by reference (orl_fk_ord)
;

create unique index orl_pk on order_lines (id_ord, line_number);
alter table order_lines add constraint orl_pk primary key (id_ord, line_number);

create table order_lines_2 (
        date_ordered    date,
        id_ord          number(10,0) not null,
        line_number     number(4,0)  not null,
        id_product      number(6,0)  not null,
        qty             number(6,0)  not null,
        value           number(10,2) not null,
        padding         varchar2(150),
        constraint orl2_fk_ord foreign key (id_ord) references orders
                on delete cascade
)
partition by range (date_ordered)
(
        partition p201801       values less than (to_date('01-Feb-2018')),
        partition p201802       values less than (to_date('01-Mar-2018')),
        partition p201803       values less than (to_date('01-Apr-2018')),
        partition p201804       values less than (to_date('01-May-2018')),
        partition p201805       values less than (to_date('01-Jun-2018')),
        partition p201806       values less than (to_date('01-Jul-2018')),
        partition p201807       values less than (to_date('01-Aug-2018'))
)
;

create unique index orl2_pk on order_lines_2 (id_ord, line_number);
alter table order_lines_2 add constraint orl2_pk primary key (id_ord, line_number);

It’s a bit of a bodge job as far as modelling goes, but that’s to keep workload comparisons easy and make a point without writing too much code. All I’ve got is an orders table partitioned by date and an order_lines table that I want partitioned the same way. I’ve handled the requirement for partitioning order_lines in two ways, one is partition by reference and the other is to copy down the partitioning column from the orders table. (In my view the “real” key for an orders table should be (customer identifier, order date, counter) and if I thought efficient partitioning was going to be a necessary feature for scalability I would copy down all three columns. Depending on the nature of the business I would compress the primary key index on orders on one or two of the columns, and the foreign key index on order_lines on one, two, or three of its columns)

Now all I have to do is load some data into the tables. First the orders table:

insert into orders(
        id, id_cust, date_ordered, padding
)
with g as (
        select rownum id from dual
        connect by level <= 1e4
)
select
        rownum                                  id,
        trunc(dbms_random.value(10000,20000))   id_cust,
        to_date('01-Jan-2018') +
                trunc((rownum-1)/100)           date_ordered,
        rpad('x',40)                            padding
from
        g,g
where
        rownum <= 2e4
;

commit;
execute dbms_stats.gather_table_stats(user,'orders')

This produces 100 orders per day, for 200 days which fits within the seven months of pre-declared partitions. I’ve gathered table stats on the table because that’s probably the best way to deal with any requirements for block cleanout after the insert. (Note: I’m avoiding interval partitioning in this example because that’s just another complication to add to the comparison and, as I reported a few days ago, introduces another massive inefficiency on data loading.)

Now I’ll insert some order_lines rows at 5 lines per order into the two versions of the order_lines tables. One of them, of course, has to have a date generated using the same algorithm that I used for the orders table. Note that I’ve made a call to dbms_random.seed(0) before each insert to guarantee that the same “random” values will be inserted in both table.

execute dbms_random.seed(0)

insert into order_lines_2(
        date_ordered, id_ord, line_number, id_product, qty, value, padding
)
with g as (
        select rownum id from dual
        connect by level <= 1e4
)
select
        to_date('01-Jan-2018') +
                trunc((rownum-1)/500)           date_ordered,
        1 + trunc((rownum-1)/5)                 id_ord,
        1 + mod(rownum,5)                       line_number,
        trunc(dbms_random.value(10000,20000))   id_product,
        1 qty,
        1 value,
        rpad('x',80)                            padding
from
        g,g
where
        rownum <= 10e4
;

commit;


execute dbms_random.seed(0)

insert into order_lines(
        id_ord, line_number, id_product, qty, value, padding
)
with g as (
        select rownum id from dual
        connect by level <= 1e4
)
select
        1 + trunc((rownum-1)/5)                 id_ord,
        1 + mod(rownum,5)                       line_number,
        trunc(dbms_random.value(10000,20000))   id_product,
        1 qty,
        1 value,
        rpad('x',80)                            padding
from
        g,g
where
        rownum <= 10e4
;

commit;

What I haven’t shown in the code is the snapshot wrapping I used to check the session stats, system latch activity and system rowcache activity – which I thought would give me the best indication of any variation in workload. In fact, of course, the first and simplest variation was the elapsed time: 4.5 seconds for the ref partitioned table, 2.5 seconds for the explicitly created table (regardless of which insert I did first), and it was nearly all pure CPU time.

It turned out that the rowcache stats showed virtually no variation, and the latch stats only showed significant variation in the latches that I could have predicted from the session stats, and here are the most significant session stats that highlight and explain the difference in times:

Explicitly Created
------------------
CPU used by this session                                                   231
DB time                                                                    242
db block gets                                                          219,471
db block changes                                                        27,190
redo entries                                                            15,483
redo size                                                           24,790,224
HSC Heap Segment Block Changes                                           2,944

Ref partitioned
---------------
CPU used by this session                                                   515
DB time                                                                    532
db block gets                                                          615,979
db block changes                                                       418,025
redo entries                                                           209,918
redo size                                                           70,043,676
HSC Heap Segment Block Changes                                         100,048

These results were from 12.1.0.2, but the figures from 12.2.0.1 and 11.2.0.4 were similar though the CPU time dropped as the version number went up: what you’re seeing is the effect of turning an array insert (for the precreated table) into single row processing for the ref partitioned table. Basically it seems that for every row inserted Oracle has to do something to work out which partition the row should go into, and while it does that work it release any pins of buffers it would have been holding from the previous row’s insert; in other words, various optimisations relating to array inserts are not taking place.

  • Looking in more detail at the figures for the ref partition insert:
  • The 100,000 “HSC heap Segment Block Changes” equate to the 100,000 rows inserted into the table
  • Add the single row index updates to the primary key and you get 200,000 redo entries.
  • For every individual row inserted Oracle has to do a current mode (db block gets) check against the primary key of the orders table – but when array processing the root block can be pinned.

We can get a closer look at the differences by taking snapshots of v$segstat (or v$segment_statistics), to see the following (pre-created table on the left):


ORD_PK                                |   ORD_PK
  logical reads          199,440      |     logical reads          300,432
                                      |
ORDER_LINES_2 - P201801               |   ORDER_LINES - P201801
  logical reads            2,112      |     logical reads           16,960
  db block changes         1,280      |     db block changes        16,944
                                      |
ORDER_LINES_2 - P201802               |   ORDER_LINES - P201802
  logical reads            2,256      |     logical reads           16,144
  db block changes         1,248      |     db block changes        15,088
                                      |
ORDER_LINES_2 - P201803               |   ORDER_LINES - P201803
  logical reads            2,288      |     logical reads           17,264
  db block changes         1,376      |     db block changes        16,560
                                      |
ORDER_LINES_2 - P201804               |   ORDER_LINES - P201804
  logical reads            2,672      |     logical reads           16,768
  db block changes         1,280      |     db block changes        16,144
                                      |
ORDER_LINES_2 - P201805               |   ORDER_LINES - P201805
  logical reads            2,224      |     logical reads           17,472
  db block changes         1,264      |     db block changes        16,528
                                      |
ORDER_LINES_2 - P201806               |   ORDER_LINES - P201806
  logical reads            2,624      |     logical reads           16,800
  db block changes         1,328      |     db block changes        16,160
                                      |
ORDER_LINES_2 - P201807               |   ORDER_LINES - P201807
  logical reads            1,376      |     logical reads           10,368
  db block changes           864      |     db block changes        10,752
                                      |
ORL2_PK                               |   ORL_PK
  logical reads           10,640      |     logical reads          206,352
  db block changes         7,024      |     db block changes       104,656

The right hand data set does an extra 100,000 logical reads on the ORD_PK index (top set of lines) which I think are the 100,000 gets on the root block that was pinned for the table on the left – the numbers don’t quite add up, so there’s some extra complexity that I haven’t guessed correctly.

The insert into the ORL[2]_PK index (lines) is single row processed for the right hand table – with, I think, the logical reads recording two current gets per insert.

Every partition of the table, except the last, shows 15,000 db block changes, totalling a difference of about 100,000 db block changes corresponding to the single rows being inserted. Then ORL[2]_PK shows another 100,000 db block changes, giving us the 200,000 we saw as redo entries and 400,000 (when doubled up to allow for the undo) db block changes that we saw in total.

Finally we need to explain the difference of 400,000 db block gets between the two sets of session stats – and I think this is the extra 100,000 for ORD_PK, the 100,000 for the table inserts, and 200,000 for the ORL[2]_PK index, which I think might be explained as 100,000 as a current get that checks for “duplicate key” and 100,000 gets to do the actual insert.

Bottom Line, though – if you use reference partitioning every array insert seems to turn into single row processing with the attendant increase in buffer gets, undo and redo generated,  latch activity, and CPU used as Oracle checks for every single row which partition it should go into: and there doesn’t seem to be any optimisation that caters for “this row belongs in the same partition as the previous row”. You may decide that this extra cost due to reference partitioning is worth it for the benefits that reference partitioning supplies – it’s all down to what your application does, especially in terms of aging data perhaps – but it’s nice to know that this cost is there so that you can do a better cost/benefit analysis.

Footnote:

Interested readers might like to extend this test to a multi-layered set of ref-partitioned tables to see if the increase in overheads is linear or geometric.

 

Result cache invalidation caused by DML locks

In a previous post about Result Cache, I was using ‘set autotrace on’ in my session to see when the result cache hit saves the logical reads. I got a comment, by e-mail and with full test case, mentioning that the invalidation I had when doing some DML does not occur when autotrace is set to off. I reproduced the problem, on 18c because I use my cloud services to do my tests, but it works the same way in 12c.

I’ll focus here on DML which does not modify any rows from the table the result depends on, because this is the case that depends on the session transaction context. When rows are modified, the result is always invalidated.

For each test here I’ll flush the result cache:

SQL> exec if dbms_result_cache.flush then dbms_output.put_line('Flushed.'); end if;
PL/SQL procedure successfully completed.
 
SQL> select id,type,status,name,cache_id,invalidations from v$result_cache_objects order by id
no rows selected

And I begin each test with the result cache loaded by a query.

DML on the dependent table

The result or the query is loaded into the cache, with a dependency on the SCOTT.DEPT table:

SQL> select id,type,status,name,cache_id,invalidations from v$result_cache_objects order by id
 
ID TYPE STATUS NAME CACHE_ID INVALIDATIONS
-- ---- ------ ---- -------- -------------
0 Dependency Published SCOTT.DEPT SCOTT.DEPT 0
1 Result Published select /*+ result_cache */ count(*) from DEPT 50vtzqa5u0xcy4bnh6z600nj1u 0

Now, I’m executing some DML on this DEPT table:

SQL> connect scott/tiger@//localhost/PDB1
Connected.
SQL> delete from DEPT where DEPTNO>40;
0 rows deleted.

This delete does not touch any row, but declares the intention to modify the table with a Row eXclusive lock (TM mode=3):

SQL> select * from v$locked_object natural join (select object_id,object_name from user_objects)
 
OBJECT_ID XIDUSN XIDSLOT XIDSQN SESSION_ID ORACLE_USERNAME OS_USER_NAME PROCESS LOCKED_MODE CON_ID OBJECT_NAME
--------- ------ ------- ------ ---------- --------------- ------------ ------- ----------- ------ -----------
73376 0 0 0 21 SCOTT oracle 7772 3 5 DEPT

Note that the transaction ID is all zeros. Logically, we are in a transaction, as we have a lock that will be released only at the end of the transaction (commit or rollback). But, as we didn’t modify any block yet, there is no entry in the transaction table:

SQL> select xidusn,xidslot,xidsqn,start_time,used_urec from v$transaction
no rows selected

I commit this transaction:

SQL> commit;
Commit complete.

and check the result cache objects:

SQL> select id,type,status,name,cache_id,invalidations from v$result_cache_objects order by id
 
ID TYPE STATUS NAME CACHE_ID INVALIDATIONS
-- ---- ------ ---- -------- -------------
0 Dependency Published SCOTT.DEPT SCOTT.DEPT 0
1 Result Published select /*+ result_cache */ count(*) from DEPT 50vtzqa5u0xcy4bnh6z600nj1u 0

This look good: nothing was modified so there is no reason to invalidate the result. However, in the previous post I referenced, a similar test invalidated the cache even when no rows were touched. And a reader remarked that this occured only when I previously run a query with ‘autotrace on’. Without autotrace, the behaviour is like what I show here above: no invalidation when no rows is modified.

Same in an already started transaction

The difference is that the ‘autotrace on’ runs an ‘explain plan’, filling the plan table, which means that a transaction was already started. Here I run autotrace on a completely different query:

SQL> set autotrace on explain
Autotrace Enabled
Displays the execution plan only.
SQL> select * from dual;
DUMMY
-----
X
 
Explain Plan
-----------------------------------------------------------
PLAN_TABLE_OUTPUT
Plan hash value: 272002086
 
--------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 2 | 2 (0)| 00:00:01 |
| 1 | TABLE ACCESS FULL| DUAL | 1 | 2 | 2 (0)| 00:00:01 |
--------------------------------------------------------------------------
 
SQL> set autotrace off;
Autotrace Disabled

Following this, I have no locked objects, but a transaction has been initiated:

SQL> select * from v$locked_object natural join (select object_id,object_name from user_objects)
no rows selected
 
SQL> select xidusn,xidslot,xidsqn,start_time,used_urec from v$transaction
XIDUSN XIDSLOT XIDSQN START_TIME USED_UREC
------ ------- ------ ---------- ---------
9 18 709 03/18/18 20:30:09 2

Here is the big difference: I have a transaction ID here.
Now doing the same as before, a delete touching no rows:

SQL> delete from DEPT where DEPTNO>40;
0 rows deleted.

When I query the lock objects, they are now associated to a non-zero transaction ID:

SQL> select * from v$locked_object natural join (select object_id,object_name from user_objects)
 
OBJECT_ID XIDUSN XIDSLOT XIDSQN SESSION_ID ORACLE_USERNAME OS_USER_NAME PROCESS LOCKED_MODE CON_ID OBJECT_NAME
--------- ------ ------- ------ ---------- --------------- ------------ ------- ----------- ------ -----------
73376 9 18 709 21 SCOTT oracle 7772 3 5 DEPT

Here is the difference, now the result cache has been invalidated:

SQL> commit;
Commit complete.
 
SQL> select id,type,status,name,cache_id,invalidations from v$result_cache_objects order by id
 
ID TYPE STATUS NAME CACHE_ID INVALIDATIONS
-- ---- ------ ---- -------- -------------
0 Dependency Published SCOTT.DEPT SCOTT.DEPT 1
1 Result Invalid select /*+ result_cache */ count(*) from DEPT 50vtzqa5u0xcy4bnh6z600nj1u 0

DML on another table – RS though referential integrity

CaptureLocksThis gives the idea that the invalidation is not really triggered by actual modifications, but at commit time from the DML locks when associated with a transaction.
And some DML on tables may acquire a Row-S or Row-X lock on the tables linked by referential integrity. This has changed a lot though versions – look at the slide on the right.

I start in the same situation, with the result cache loaded, no locked objects, but a transaction that has started:

SQL> select id,type,status,name,cache_id,invalidations from v$result_cache_objects order by id
 
ID TYPE STATUS NAME CACHE_ID INVALIDATIONS
-- ---- ------ ---- -------- -------------
0 Dependency Published SCOTT.DEPT SCOTT.DEPT 0
1 Result Published select /*+ result_cache */ count(*) from DEPT 50vtzqa5u0xcy4bnh6z600nj1u 0
 
SQL> select * from v$locked_object natural join (select object_id,object_name from user_objects)
no rows selected
 
SQL> select xidusn,xidslot,xidsqn,start_time,used_urec from v$transaction
 
XIDUSN XIDSLOT XIDSQN START_TIME USED_UREC
------ ------- ------ ---------- ---------
8 31 766 03/18/18 20:30:10 2

I delete from the EMP table and if you are familiar with the SCOTT schema, you know that it has a foreign key to DEPT.

SQL> delete from EMP where DEPTNO>=40;
0 rows deleted.

The delete acquires a Row eXclusive lock on EMP even when there are no rows deleted (DML locks are about the intention to modify rows). And from the table above, it acquires a Row Share (mode=2) on the parent table:

SQL> select * from v$locked_object natural join (select object_id,object_name from user_objects)
 
OBJECT_ID XIDUSN XIDSLOT XIDSQN SESSION_ID ORACLE_USERNAME OS_USER_NAME PROCESS LOCKED_MODE CON_ID OBJECT_NAME
--------- ------ ------- ------ ---------- --------------- ------------ ------- ----------- ------ -----------
73376 8 31 766 21 SCOTT oracle 7772 2 5 DEPT
73378 8 31 766 21 SCOTT oracle 7772 3 5 EMP

I commit and check the result cache:

SQL> commit;
Commit complete.
 
SQL> select id,type,status,name,cache_id,invalidations from v$result_cache_objects order by id
 
ID TYPE STATUS NAME CACHE_ID INVALIDATIONS
-- ---- ------ ---- -------- -------------
0 Dependency Published SCOTT.DEPT SCOTT.DEPT 0
1 Result Published select /*+ result_cache */ count(*) from DEPT 50vtzqa5u0xcy4bnh6z600nj1u 0

No invalidation here, which makes sense because Row Share is not an intention to write.

DML on another table – RX though referential integrity

I do the same here, but with an insert on EMP which acquires a Row eXclusive on the parent table.

SQL> insert into EMP(EMPNO,DEPTNO)values(9999,40);
1 row inserted.
 
SQL> select * from v$locked_object natural join (select object_id,object_name from user_objects)
 
OBJECT_ID XIDUSN XIDSLOT XIDSQN SESSION_ID ORACLE_USERNAME OS_USER_NAME PROCESS LOCKED_MODE CON_ID OBJECT_NAME
--------- ------ ------- ------ ---------- --------------- ------------ ------- ----------- ------ -----------
73376 10 32 560 21 SCOTT oracle 7772 3 5 DEPT
73378 10 32 560 21 SCOTT oracle 7772 3 5 EMP
 
SQL> select xidusn,xidslot,xidsqn,start_time,used_urec from v$transaction
 
XIDUSN XIDSLOT XIDSQN START_TIME USED_UREC
------ ------- ------ ---------- ---------
10 32 560 03/18/18 20:30:10 4
 
SQL> commit;
Commit complete.
 
SQL> select id,type,status,name,cache_id,invalidations from v$result_cache_objects order by id
---- ------ ------------------------------------------ ---- ---------------------- ----- -- --
ID TYPE STATUS NAME CACHE_ID INVALIDATIONS
0 Dependency Published SCOTT.DEPT SCOTT.DEPT 1
1 Result Invalid select /*+ result_cache */ count(*) from DEPT 50vtzqa5u0xcy4bnh6z600nj1u 0

Here, DEPT has been invalidated after the insert on EMP. There were no modifications on DEPT, but the result cache is not directly tracking the modifications, but rather the intention of modification. And then, the implementation of the result cache invalidation tracks, at commit, the Row eXclusive locks when they are related to a know transaction. You can have the same result if, from a transaction that has already started, you run a simple:

SQL> lock table DEPT in row exclusive mode;
Lock succeeded.

This means that there are many reasons why the result cache may be invalid even when the objects in the ‘Dependency’ are not modified. Be careful, invalidations and cache misses are expensive and do not scale on high load. And because of locks through referential integrity, this can happen even on static tables. Let’s take an example. in an order entry system, you may think that the ‘products’ table is a good candidate for result cache – updated twice a year but read all the times. But now that you know that inserts on child tables, such as the order table, will invalidate this cache, you may think again about it.

 

Cet article Result cache invalidation caused by DML locks est apparu en premier sur Blog dbi services.