Got to know from the team , there was a stats gathering process running
multiple times as part of the same data load process but as it was
consuming a lot of time/resources it was removed and now stats gathering is
happening at the end of the load. and it seems after removing that stats
gathering process the data load seems to be degraded. Though the
v$sessstats doesn't show that exact statistics(transaction table consistent
read undo records applied) but then, Can it be related to something
similar to the delayed block cleanout effect related to the past DELETE
operation?
On Wed, Aug 4, 2021 at 1:25 AM Pap <oracle.developer35@xxxxxxxxx> wrote:
I am able to get hold of two different runs for 10minutes duration and I
captured the stats from the v$views. The slow run as stated by
the application team was not extremely slow but it was slower as compared
to fast run. I was not able to figure out much from the session stats
though. But comparison if the 'cell single block physical read' wait time
from the v$event histogram for both the fast and slow run looks as below.
Does it mean that we are simply doing more work during the slow run period
which may be because of something similar to delayed block cleanout but not
exactly that(as we don't see that stats in v$sessstat) as highlighted by
lothar earlier. So it's doing some tidying up of the block post delete and
thus doing more work during INSERT? I do see few 'backup' related stats in
v$system_event , but that is visible in both the slow and fast run
scenario.
Don't have the rights to create a function so I have captured the stats
from v$ views manually when the insert started and then after ~10minutes
past and added to the attached excel sheet for both fast and slow run. Did
the same for both fast and slow runs. Below results from v$event_histogram
is a difference/delta of those numbers. Anything else I should look at from
these captured v$ view stats to get some more clue?
EVENT WAIT_TIME_MILLI Slow run(Delta Wait_count) Fast run (Delta Wait
count)
cell single block physical read 1 2655942 1414931
cell single block physical read 2 56441 5459
cell single block physical read 4 37837 1374
cell single block physical read 8 28521 393
cell single block physical read 16 11066 291
cell single block physical read 32 1579 90
cell single block physical read 64 88 5
cell single block physical read 128 2 0
cell single block physical read 256 1 0
cell single block physical read 512 0 0
cell single block physical read 1024 0 0
cell single block physical read 2048 0 0
cell single block physical read 4096 0 0
cell single block physical read 8192 0 0
On Sat, Jul 31, 2021 at 10:18 PM Jonathan Lewis <jlewisoracle@xxxxxxxxx>
wrote:
It's good to see the session activity stats for a timed period.
In this case your figures are showing us that the two runs are basically
doing the same work in the same way, but the slower session is suffering
from slow (real) disk I/O, and getting a slighlty smaller fraction of its
"disk" reads from cell flash cache. (Note that physical reads = physical
read I/O requests, so it's all single block, which is consistent with
seeking and updating the index; note also that the "cell flash cache read
hits" is only a small fraction of the physical read I/O requests. so the
drop from 2.07% to 1.69% is not particularly significant.
There is one interesting pair of numbers - though it's not telling us
anything about performance. You've inserted (in the good run) roughly 38M
rows in this interval; but the "Heap Segment Array Inserts" is 1.2M, which
means (internally) Oracle is inserting about 30 rows per array (compared to
your (external) array size of 352). But your figures for the size of the
table (215GB, 1.7B rows) suggest a block should hold about 65 rows, and
your delete "where cr_date < sysdate - 3" with no supporting index suggests
a tablescan path which we might expect to empty blocks completely. This
combination suggests there's a pattern created by past activity that could
be producing interesting side-effects. (NOTE, though that whatever is
happening it's happening in both the good and bad here, so this oddity
isn't an explanation for the difference).
Although the session activity stats haven't provided an answer, they have
eliminated some possibilities, so it is a step forward. The thing to do now
is to extend the information you are collecting. Most of the time is I/O
wait time, but there is some other time to account, and the exact breakdown
of I/O time would be interesting; so next steps would be:
1) repeat this capture, but gather the session's event wait time
(v$session_event) at the same time, and the SYSTEM stats and event times so
that we can see if there's anything happening outside this session that is
causing this session's I/O time. If possible, add to that capture the
capture of the event histogram - v$event_histogram which will give you some
idea of how even (or not) the slowness is by giving you a numeric summary
histogram of the event times. There's an example at this URL:
https://jonathanlewis.wordpress.com/2008/06/15/event-snapshots/ showing
how I've set up some tests in the past, but it's easier in the short term
to just take two snapshots and find the difference.
2) If all else fails to supply any clues enable sql_trace remotely for
the session for a limited period with wait state tracing enabled to see if
you can spot any pattern in the disk reads and times taken.
Regards
Jonathan Lewis
On Fri, 30 Jul 2021 at 12:13, Pap <oracle.developer35@xxxxxxxxx> wrote:
Thank you Mark.
I was wondering if it's a good idea to partition this table just to help
it purge in a cleaner fashion. As because, if we just partition it to make
our purging better we also have to see the impact on the read queries. To
have the table partitioned with the delete key(i.e. create_timestamp), the
primary key also has to include the delete key in it or else it will not
allow it to make it a local index. And in case of global index we will have
to go through index invalidation/rebuild stuff both in case of drop or
partition exchange etc. And also the read queries now have to go through
multiple local index segments scan vs the current one segment scan.
I was trying to see/prove if it's really delayed block cleanout
impacting INSERT, So i tried to collect the stats from v$sesstat for
two different executions/data loads for close to ~10minutes duration though
it's not exact(i think i monitored the bad execution for a bit longer
duration). And as v$sesstat accumulates the statistics so I collected the
delta value for each run. As per application, the first execution was
running slow and the next one was running with better response. Attached
are the stats for the same. But surprisingly I see the delta value of
statistics 'transaction table consistent read - Undo records applied' is
zero in both the cases. So I'm wondering if there are some other
phenomena(other than delayed block cleanout) which are happening here and
how can we fix? In both the cases I see from ASH the wait event (cell
single block physical read) was highest logged against the table
followed by the PK index.
On Fri, Jul 30, 2021 at 3:10 AM Mark W. Farnham <mwf@xxxxxxxx> wrote:
That’s right.
But what you probably **should** do is partition the table by your
delete key. And if you can change the insert into append, then you just
partition exchange out and drop the unwanted rows with nary a delete seen.
That also gives you a cheap ability to archive the swapped out partition to
a table to back up as a stand alone period of time.
Good luck. IF Lothar’s suggestion of delayed block cleanout is correct,
either of these things should fix it. IF the deleted space being used
dramatically increasing the number of blocks you need to read via an
indexed access path by fubaring the actual cluster factor, the partitioning
fixes that.
*From:* Pap [mailto:oracle.developer35@xxxxxxxxx]
*Sent:* Thursday, July 29, 2021 3:49 PM
*To:* Mark W. Farnham
*Cc:* Lothar Flatz; Oracle L
*Subject:* Re: Insert Query issue
Thanks Mark. If I get it correct , you are suggesting a method to
scan the blocks in the buffer cache which are getting deleted. But
considering we are going to hold ~3days worth of data at any point in time,
I was thinking if it's easy one to just scan or gather stats with auto
sample size after delete to get the blocks cleaned. but before that is it
the same effect i.e. delayed block cleanout which we are suffering from
here? I thought Lothar might be pointing to some other similar effect but
not exactly delayed block cleanout. Please correct me if I'm wrong.
On Fri, Jul 30, 2021 at 12:41 AM Mark W. Farnham <mwf@xxxxxxxx> wrote:
If you stash (probably insert append, then after the subsequent read
truncate) into a table the rowid of all the rows you are about to delete
(using the same predicate), then do the delete, then commit, that will give
you the list of the candidate blocks. If you read from the table you
deleted from where rowid in (select rowid from the new table) from a
different node on your Exadata, you’re probably going to get that in sga.
IF not, you can pl/sql loop them one block at a time.
*From:* oracle-l-bounce@xxxxxxxxxxxxx [mailto:
oracle-l-bounce@xxxxxxxxxxxxx] *On Behalf Of *Pap
*Sent:* Thursday, July 29, 2021 2:34 PM
*To:* Lothar Flatz
*Cc:* Oracle L
*Subject:* Re: Insert Query issue
Thank you Lothar.
It appears to be something matching to delayed block cleanout effect in
which post DML sometimes we have to perform a segment scan so that the
commit scn can be updated for all the blocks and for that sometimes we have
to do it using manual stats gathering or forced segment full scan to pass
all the data blocks through buffer cache. But for that we used to see one
stats i.e. 'transaction table consistent read undo records applied' on the
SELECT query execution.
So is this tidying up of block post delete something similar as above
and we can get that verified and confirmed from some session statistics
from v$sesstat while the insert is running at run time? Also I am thinking
what can be done so as to tidying up the blocks after delete, if a force
segment full scan or stats gather post deletion can anyway help, so as to
not impact the insert performance?
*Betreff: *
Re: Insert Query issue
*Datum: *
Thu, 29 Jul 2021 19:59:25 +0200
*Von: *
Lothar Flatz <l.flatz@xxxxxxxxxx> <l.flatz@xxxxxxxxxx>
*An: *
oracle-l@xxxxxxxxxxxxx
Hi,
there reason should be that after a delete rows are marked as technical
deleted, but the block is not yet tidied up. (I suppose that would mean
e.g. that other rows are not yet shifted for contiguous space etc.)
The tidying is done on the next insert, which therefore will be
substantially slower for once.
I heard this explanation long ago , but suppose it still holds.
My whole understanding of this is a bit vague.
I guess Jonathan could fill in some details here.
Regards
Lothar
Am 29.07.2021 um 18:10 schrieb Pap:
This legacy database is on version 11.2.0.4 of oracle Exadata.
We are having below conventional insert query introduced and its a bulk
insert happening with an arraysize of ~352 from informatica. And the
response time was ~3millisec/execution i.e. for one chunk or ~352 rows. But
we noticed suddenly the response time becomes
tripled(~8-9millisec/execution) for the same set of rows/array size insert.
No changes done to the underlying table structure.
During digging into the AWR views we found that the increase in
response time for this insert query started after we introduced the delete
script to purge data from this table. The delete is also happening in bulk
fashion with an arraysize of 100K through plsql procedure and its deleting
data with CRE_TS<sysdate-3. And it's clear from dba_hist_sqlstat that it's
the cpu_time_delta and IOWAIT_DELTA which increased thus making the
ELAPSED_TIME_delta go up by three times for the INSERT query. No such
increase in BUFFER_GETS_delta observed. But one thing we notice is that the
DELETE is not running at exactly the same time as the insert/data load
script runs. So howcome this delete is impacting the INSERT query? Is this
that as delete is making some blocks empty so that now the INSERT has to
now see through all to find the empty blocks before insert and thus
spending more time?
The table is ~215GB in size and is not partitioned holding ~1.7billion
rows. There exists only a primary key composite index on two number data
type columns. With Blevel-3 , and having index size ~65GB with ~7.3million
leaf blocks.
Below is the AWR plan for the INSERT and DELETE queries.
INSERT INTO TAB1(TAID,TID,AID,APP_NM,CRE_TS) VALUES ( :1, :2, :3,:4,
:5)
-------------------------------------------------
| Id | Operation | Name | Cost |
-------------------------------------------------
| 0 | INSERT STATEMENT | | 1 |
| 1 | LOAD TABLE CONVENTIONAL | | |
-------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
1 - INS$1
Note
-----
- cpu costing is off (consider enabling it)
DELETE FROM USER1.TAB1 WHERE ROWID = :1
Plan hash value: 2488984540
----------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows |
Bytes | Cost (%CPU)| Time |
----------------------------------------------------------------------------------------------------
| 0 | DELETE STATEMENT | | |
| 1 (100)| |
| 1 | DELETE | TAB1 | |
| | |
| 2 | TABLE ACCESS BY USER ROWID| TAB1 | 1 |
25 | 1 (0)| 00:00:01 |
----------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
1 - DEL$1
2 - DEL$1 / TAB1@DEL$1
Outline Data
-------------
/*+
BEGIN_OUTLINE_DATA
IGNORE_OPTIM_EMBEDDED_HINTS
OPTIMIZER_FEATURES_ENABLE('11.2.0.4')
DB_VERSION('11.2.0.4')
ALL_ROWS
OUTLINE_LEAF(@"DEL$1")
ROWID(@"DEL$1" "TAB1"@"DEL$1")
END_OUTLINE_DATA
*/
