Performance Tuning

Super-Sizing PGA Workareas in Oracle 12c

After a customer asked me for possibilities of super-sizing PGA workareas in version 12c, I took the chance to revisit the topic and perform some tests. Great material has already been posted by Alex Fatkulin (Hotsos Symposium 2014) and Norbert Debes (Secrets of the Oracle Database, Apress), but I wanted to verify, how the current release is behaving and I found some interesting things.

Super-Sizing PGA Workareas in 12c


Datapump Export suffering from Oracle Row Migration

Recently, i was troubleshooting a datapump export duration problem. Over the period of 18 months, the duration of a multi-table export increased dramatically. A quick analysis showed that the export duration was mainly dependent on one big table. This 50 GB table with no BLOB/CLOB/LONG datatypes took more than 4 hours on a modern system wheras it should not take more than 10 – 15 minutes. The system was performing ONLY single-block I/O requests (db file sequential read). I found this strange and started investigating.

Beginning with 11g, you can enable sql_trace (10046) for datapump with the new syntax:

ALTER system SET events 'sql_trace {process : pname = dw | pname = dm} level=12';

The trace showed that there were dozens of consecutive single-block I/O requests against the SAME data block:

WAIT #47053877709656: nam='db file sequential read' ela= 344 file#=41 block#=2556595 blocks=1 obj#=120874 tim=1347023848770469
WAIT #47053877709656: nam='db file sequential read' ela= 6 file#=41 block#=2556595 blocks=1 obj#=120874 tim=1347023848770504
WAIT #47053877709656: nam='db file sequential read' ela= 5 file#=41 block#=2556595 blocks=1 obj#=120874 tim=1347023848770526
WAIT #47053877709656: nam='db file sequential read' ela= 5 file#=41 block#=2556595 blocks=1 obj#=120874 tim=1347023848770548
WAIT #47053877709656: nam='db file sequential read' ela= 4 file#=41 block#=2556595 blocks=1 obj#=120874 tim=1347023848770570
WAIT #47053877709656: nam='db file sequential read' ela= 5 file#=41 block#=2556595 blocks=1 obj#=120874 tim=1347023848770593
WAIT #47053877709656: nam='db file sequential read' ela= 5 file#=41 block#=2556595 blocks=1 obj#=120874 tim=1347023848770617
WAIT #47053877709656: nam='db file sequential read' ela= 4 file#=41 block#=2556595 blocks=1 obj#=120874 tim=1347023848770639

No wonder that this does not perform well, right? Next was a block dump of this interesting block from file 52 / block 2056439.

SELECT * FROM dba_extents WHERE file_id = 41 AND 2556595 BETWEEN block_id AND block_id+blocks-1;
ALTER system dump datafile 41 block 2556595;

In the resulting trace file, I verified that i dumped the block from the correct table segment. (Hex 0x1d82a is Dec 120874)

buffer tsn: 15 rdba: 0x0a6702b3 (41/2556595)
frmt: 0x02 chkval: 0x57f3 TYPE: 0x06=trans DATA
seg/obj: 0x1d82a csc: 0x0c.1c3abc94 itc: 20 flg: E typ: 1 - DATA

Then I had a closer look at the flag bytes.

The flags were:

  • H: Head Piece
  • F: First Piece
  • L: Last Piece

Normally, “H-FL” is shown to indicate that the whole row is located in one rowpiece in the same block. In this block dump, you can see dozens of rows with “—-FL–” which means that the head row piece is not here and you see no Head-Piece-only Row Pieces  “–H—–” . This shows that this segment has suffered from heavy row migration. Probably, this was caused by adding columns after the table creation.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
SID_ora_999.trc | grep "^tl: "
tl: 97 fb: ----FL-- lb: 0x0 cc: 20
tl: 88 fb: --H-FL-- lb: 0x0 cc: 20
tl: 97 fb: ----FL-- lb: 0x0 cc: 20
tl: 88 fb: --H-FL-- lb: 0x0 cc: 20
tl: 98 fb: ----FL-- lb: 0x2 cc: 20
tl: 89 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 89 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 89 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 89 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 89 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 89 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 89 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 90 fb: --H-FL-- lb: 0x2 cc: 20
tl: 99 fb: ----FL-- lb: 0x2 cc: 20

With datapump there are 2 different access methods: EXTERNAL_TABLE and DIRECT_PATH. Usually, the datapump utility decides on it´s own which method to use. It turned out that with EXTERNAL_TABLE, the table export takes only 10 minutes and does not perform these single-block I/O. It only appears with DIRECT_PATH.

So, the next step I recommended was to reorganize the table to get rid of row migration and evaluate whether PCTFREE should be increased. Afterwards export durations are back to normal.



Performance Degradation for Query on DBA_SEGMENTS.BYTES in 11gR2

I have been troubleshooting a performance issue in a DWH environment, which is quite interesting. It was a query on DBA_SEGMENTS in 11gR2 with lots of partitions and it was taking almost 10 minutes versus only a few seconds in 10gR2. The problem could be stripped downt to this SQL query:

select bytes from dba_segments

The dba_segment view can be seen in DBA_VIEWS:

SELECT ...
       decode(bitand(segment_flags, 131072), 131072, blocks,
           (decode(bitand(segment_flags,1),1,
            <strong>dbms_space_admin.segment_number_blocks</strong>(tablespace_id, relative_fno,
            header_block, segment_type_id, buffer_pool_id, segment_flags,
            segment_objd, blocks), blocks)))*blocksize,
      ...
FROM sys_dba_segs

The response time was dominated by Waits for “db file sequential reads” taking almost all of the response time.

11gR2:

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch    12563     23.17     546.74     157447     580414          1      188421
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total    12565     23.17     546.74     157447     580414          1      188421

10gR2:

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.06       0.06          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch     5104      1.77       2.54          0      96688          0       76542
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total     5106      1.83       2.61          0      96688          0       76542

The 10046 Trace File contains more data regarding those waits:

WAIT #4: nam='db file sequential read' ela= 134 file#=21 block#=2313482 blocks=1 obj#=-1 
WAIT #4: nam='db file sequential read' ela= 120 file#=15 block#=2128019 blocks=1 obj#=-1 
WAIT #4: nam='db file sequential read' ela= 128 file#=21 block#=2313490 blocks=1 obj#=-1 
WAIT #4: nam='db file sequential read' ela= 372 file#=21 block#=2313498 blocks=1 obj#=-1 
WAIT #4: nam='db file sequential read' ela= 108 file#=21 block#=2313506 blocks=1 obj#=-1 
WAIT #4: nam='db file sequential read' ela= 130 file#=21 block#=2313514 blocks=1 obj#=-1 
WAIT #4: nam='db file sequential read' ela= 132 file#=21 block#=2313522 blocks=1 obj#=-1 
WAIT #4: nam='db file sequential read' ela= 121 file#=21 block#=2313530 blocks=1 obj#=-1 
WAIT #4: nam='db file sequential read' ela= 158 file#=15 block#=2128003 blocks=1 obj#=-1 
WAIT #4: nam='db file sequential read' ela= 146 file#=21 block#=2313538 blocks=1 obj#=-1 
WAIT #4: nam='db file sequential read' ela= 116 file#=21 block#=2313546 blocks=1 obj#=-1 
(Output modified for formatting)

Strange thing that obj# is -1. I made some block dumps of those blocks and found out that all those blocks (file#/block#) have something in common: They were all segment header blocks. Another strange thing was that when the query was executed a second time, all those I/O requests were performed again – so no caching.

At that point, I opened a Support service request. After a couple of weeks, Support suggested running this for each tablespace of the user segments:

EXEC  dbms_space_admin.TABLESPACE_FIX_SEGMENT_EXTBLKS('<tablespace_name>');

Finally this fixed the problem. Now, we are trying to find out why this was necessary for a database, that was freshly created with dbca 11.2.0.2 from the seeded template and filled with data pump import.



Reclaimable Space Report – Segment Advisor

Today, I tried to get a nice, clean report about objects with reclaimable space from Segment Advisor. It is no problem to display the list in Enterprise Manager Grid|DB Control, but it is not so easy in SQL*Plus.

This is what i ended up with:

 SELECT
  segment_owner ,
  segment_name,
  round(allocated_space/1024/1024) ALLOC_MB ,
  round(used_space/1024/1024) USED_MB ,
  round(reclaimable_space/1024/1024) RECLAIM_MB    ,
  (1-ROUND((used_space/allocated_space),2))*100 AS reclaim_pct
   FROM TABLE(dbms_space.asa_recommendations('TRUE', 'TRUE', 'FALSE'))
  WHERE tablespace_name IN ('TS_DATA')
AND segment_type         = 'TABLE'
AND segment_owner LIKE '%'
AND segment_name LIKE '%'
AND (reclaimable_space >= 1000000
         OR (((1-ROUND((used_space/allocated_space),2))*100)) > 30)
ORDER BY reclaimable_space DESC


Your experience with RAC Dynamic Remastering (DRM) in 10gR2?

One of my customers is having severe RAC performance issues, which appeared a dozen times so far. Each time, the performance impact lasted around 10 minutes and caused basically a hang of the application. ASH investigation revealed that the time frame of performance issues exactly matches a DRM operation of the biggest segment of the database. During the problematic time period, there are 20-50 instead of 5-10 active sessions and they are mostly waiting for gc related events: “gc buffer busy”,”gc cr block busy”, “gc cr block 2-way”, “gc current block 2-way”, “gc current request”, “gc current grant busy”, etc.

In addition, there is one single session which has wait event “kjbdrmcvtq lmon drm quiesce: ping completion” (on instance 1) and 1-3 sessions with wait event “gc remaster“. (on instance 2) The cur_obj# of the session waiting on “gc remaster” is pointing to the segment being remastered.

Does anybody have any experience with DRM problems with 10.2.0.4 on Linux Itanium?

I know that it is possible to deactive DRM, but usually it should be beneficial to have it enabled. I could not find any reports of performance impact during DRM operation on metalink. Support is involved but clueless so far.

Regards,
Martin

http://forums.oracle.com/forums/message.jspa?messageID=3447436#3447436



SQL Profiler TVD$XTAT update available

I just saw that Christian Antognini has released an update of TVD$XTAT. I am looking forward to experimenting with it. If you used tkprof in the past, you should definitely take a look at this tool.



Excellent Presentations on

The database specialist Riyaj Shamsudeen from The Pythian Group has published some excellent presentations on his blog. Don´t miss it!



Online Redefinition on Mission Critical Siebel database

I have documented a successful online redefinition operation on a mission-critical Siebel database. It was performed after a big portion of the rows have been deleted. Additionally, row chaining was removed.

The paper can be found in the “papers” section or downloaded here: Online Reorganisation with DBMS_REDEFINITION