Oracle Tips and Tricks — David Fitzjarrell

January 26, 2016

Heap Of Trouble

Filed under: General — dfitzjarrell @ 07:31

"But I suppose there's a lot to see everywhere, if only you keep your eyes open."
-- Norton Juster, The Phantom Tollbooth 

Oracle Support recently updated what I call a ‘blast from the past’; it involves a subpool memory leak in Oracle 11.2.0.1 and shared cursors. Originally submitted in 2010 this issue was updated the end of last year (2015) to reflect the status of ‘Fixed in Product Version 12.1’. There have been several bug fixes to the 11.2.0 series of releases addressing this and similar issues, but I suspect Oracle Support waited for its declaration of ‘fixed’ until 12.1.0.2 was finally released. Let’s look at the symptoms and show how you can investigate the shared pool subpools without generating a trace file.

This issue finally becomes apparent when an ORA-04031 error is thrown:


ORA-4031: unable to allocate ... bytes of shared memory ("shared pool","STANDARD","PLMCD^e93dbe75","BAMIMA: Bam Buffer")

In the original submission a trace file for the 4031 error, generated by the database, was submitted which revealed the offending portion of subpool 2:


Memory Utilization of Subpool 1
================================
"free memory              "      25488576
"SQLA                     "     134248904
"PCUR                     "      25094632
Memory Utilization of Subpool 2
================================
"free memory              "     127129872
"PCUR                     "    2427488432

Notice that the PCUR area in subpool 2 is almost 100 times the size of the same area in subpool 1. Unfortunately an AWR report shows only the Shared Pool Size, not a breakdown of the various subpools in the Shared Pool. Fortunately Tanel Poder has provided a tool to print out the various memory segments in the subpools called sgastatx.sql that can be used to see how much memory is allocated to each subpool by reporting on all of the memory areas of interest. Looking at an example of how the script is run:


SQL> @sgastatx %

-- All allocations:

SUBPOOL                             BYTES         MB
------------------------------ ---------- ----------
shared pool (0 - Unused):        83886080         80
shared pool (1):                184549376        176
shared pool (Total):            268435456        256

-- Allocations matching "%":

SUBPOOL                        NAME                       SUM(BYTES)         MB
------------------------------ -------------------------- ---------- ----------
shared pool (0 - Unused):      free memory                  83886080         80

shared pool (1):               free memory                  41599128      39.67
                               SQLA                         14559048      13.88
                               KGLH0                        12547880      11.97
                               row cache                     8641136       8.24
                               KGLS                          7616536       7.26
                               db_block_hash_buckets         5836800       5.57
                               KGLSG                         5267216       5.02
                               dbwriter coalesce buffer      4194816          4
                               KCB Table Scan Buffer         4194816          4
                               kglsim hash table bkts        4194304          4
...

The default behavior of the script is to report everything, so the % parameter is not necessary. Other text parameters can be passed to return memory areas of concern, in this case the KGLH0 area which maps to the PCUR data reported in the trace file. Returning only the KGLH0 allocations:


SQL> @sgastatx KGLH0

-- All allocations:

SUBPOOL                             BYTES         MB
------------------------------ ---------- ----------
shared pool (0 - Unused):        83886080         80
shared pool (1):                184549376        176
shared pool (Total):            268435456        256

-- Allocations matching "KGLH0":

SUBPOOL                        NAME                       SUM(BYTES)         MB
------------------------------ -------------------------- ---------- ----------
shared pool (1):               KGLH0                        12560024      11.98


SQL>

In the database used for these runs only one subpool is allocated outside of subpool 0, which is the free memory not yet allocated to a subpool. As allocations to various subpools are made subpool 0 decreases in size until all of the unallocated free space is consumed. This can result in ‘lopsided’ allocations to some subpools; once memory is allocated to a particular subpool it cannot be re-allocated to another subpool. In ‘normal’ cases when ORA-04031 errors arise expanding the shared pool will correct them, provided dynamic shared pool allocations are configured by setting sga_max_size larger than sga_target. In extreme cases, such as this memory leak, the only solution is to restart the database to clear out the existing memory segments.

The sgastatx.sql script can be run at any time, won’t impact performance and will provide the current allocations allowing the DBA to monitor the subpool segments so proactive changes can be made to prevent ORA-04031 errors, again provided dynamic shared pool allocations are configured.

The sgastatx.sql script can also report on the free space in all allocated subpools as well as in subpool 0:


SQL> @sgastatx "free memory"

-- All allocations:

SUBPOOL                             BYTES         MB
------------------------------ ---------- ----------
shared pool (0 - Unused):        83886080         80
shared pool (1):                184549376        176
shared pool (Total):            268435456        256

-- Allocations matching "free memory":

SUBPOOL                        NAME                       SUM(BYTES)         MB
------------------------------ -------------------------- ---------- ----------
shared pool (0 - Unused):      free memory                  83886080         80

shared pool (1):               free memory                  37168136      35.45


SQL>

When subpool 0 is exhausted it will be eliminated from the displayed output, which will indicate that Oracle can make no more adjustments to the existing subpools and either a dynamic shared pool increase needs to be executed or, failing that, the spfile needs to be changed, the database stopped and then restarted. [If an spfile is not in use then the pfile needs to be modified to reflect the memory increase, followed by a shutdown and startup of the database. For ease of administration it is recommended that an spfile, rather than a pfile, be used.]

The ideal solution to this issue is to either patch to the terminal release of 11.2.0 (11.2.0.5) or upgrade to 12.1.0.2 so the memory-related bugs can be patched. It is possible that a third-party application may not be certified for any release newer than 11.2.0.1 (which should be an extremely rare case) then the next solution is to apply relevant patches for 11.2.0.1. Oracle Support lists 8 merge patches for bug fixes related to this memory leak (18730652, 18837746, 18980005, 19015163, 19494335, 19481242, 21078557 and 21076074).

Hopefully those shops still running on the base version 11.2.0.1 are few and far between, but anything is possible. Being prepared is the best way a DBA can quickly and reliably address issues, even those needing a bit of research.

Apparently there is quite a bit to see, if you look.

January 8, 2016

“Say What?!?!?”

Filed under: General,Indexes,Performance — dfitzjarrell @ 16:04

"The only thing you can do easily is be wrong, and that's hardly worth the effort." 

Norton Juster, The Phantom Tollbooth

Oracle can lie to you. Not like a disreputable used-car salesman but more like the ‘little white lie’ sometimes told in order to hide less-than-desirable parts of the truth. And it’s not Oracle, really, it’s the optimizer and it does it by reporting query plans that may not accurtely report the execution path. Sometimes we can make Oracle tell lies that it doesn’t know its telling, by using features not everyone uses. Take, for example, NLS settings. There have been improvements in National Language Support in most Oracle releases, and those improvements can introduce behavior that causes Oracle to lie to you. Let’s look at an example where this is true.

Jonathan Lewis brought this example to light in a recent blog post where he dislplayed the plan using dbms_xplan. After reading the post I decided to add to it by using autotrace to generate the plan, just to see if the two plans matched. Let’s look at the modified example:


SQL> --
SQL> --  Setup NLS parameters
SQL> --
SQL> ALTER session SET nls_sort=binary_ci;

Session altered.

SQL> ALTER session SET nls_comp=linguistic;

Session altered.

SQL> 
SQL> --
SQL> -- Create table, populate table and
SQL> -- create index
SQL> --
SQL> CREATE TABLE log_data(
  2    account_id NUMBER,
  3    log_type NUMBER,
  4    sys_name VARCHAR2(30),
  5    log_time TIMESTAMP,
  6    msg varchar2(4000)
  7  )
  8  nologging
  9  ;

Table created.

SQL> 
SQL> insert /*+ append */ into log_data(
  2    account_id,
  3    log_type,
  4    sys_name,
  5    log_time,
  6    msg
  7  )
  8  select
  9  	     5,
 10  	     2,
 11  	     dbms_random.string('a',1),
 12  	     sysdate + dbms_random.value,
 13  	     rpad('x',200)
 14  from
 15  	     dual
 16  connect by
 17  	     level  user,
  4  		     tabname	      =>'LOG_DATA',
  5  		     method_opt       => 'for all columns size 1'
  6  	     );
  7  end;
  8  /

PL/SQL procedure successfully completed.

SQL> 

The setup is complete so let’s see what autotrace reports as the execution plan:


SQL> 
SQL> column msg format a20
SQL> 
SQL> --
SQL> -- Use autotrace to generate the plan
SQL> --
SQL> set autotrace on
SQL> 
SQL> SELECT
  2  	     *
  3  FROM
  4    (
  5  	 SELECT
  6  	     sys_name, log_time,  substr(msg,1,40) msg
  7  	 FROM log_data
  8  	 WHERE
  9  	   account_id=5
 10  	   AND log_type=2
 11  	   AND sys_name='a'
 12  	 ORDER BY
 13  	   log_time  desc
 14    )
 15  WHERE
 16    rownum <= 10
 17  ;

SYS_NAME                       LOG_TIME                                                                    MSG                                        
------------------------------ --------------------------------------------------------------------------- --------------------                       
A                              09-JAN-16 02.42.54.000000 PM                                                x                                          
a                              09-JAN-16 02.41.02.000000 PM                                                x                                          
a                              09-JAN-16 02.40.54.000000 PM                                                x                                          
a                              09-JAN-16 02.36.38.000000 PM                                                x                                          
A                              09-JAN-16 02.36.02.000000 PM                                                x                                          
a                              09-JAN-16 02.34.15.000000 PM                                                x                                          
a                              09-JAN-16 02.31.15.000000 PM                                                x                                          
A                              09-JAN-16 02.30.59.000000 PM                                                x                                          
a                              09-JAN-16 02.30.36.000000 PM                                                x                                          
a                              09-JAN-16 02.29.53.000000 PM                                                x                                          

10 rows selected.


Execution Plan
----------------------------------------------------------                                                                                            
Plan hash value: 1444908817                                                                                                                           
                                                                                                                                                      
--------------------------------------------------------------------------------------------                                                          
| Id  | Operation                       | Name     | Rows  | Bytes | Cost (%CPU)| Time     |                                                          
--------------------------------------------------------------------------------------------                                                          
|   0 | SELECT STATEMENT                |          |    10 |  1120 |    13   (0)| 00:00:01 |                                                          
|*  1 |  COUNT STOPKEY                  |          |       |       |            |          |                                                          
|   2 |   VIEW                          |          |    11 |  1232 |    13   (0)| 00:00:01 |                                                          
|*  3 |    SORT ORDER BY STOPKEY        |          |    11 |  2453 |    13   (0)| 00:00:01 |                                                          
|   4 |     TABLE ACCESS BY INDEX ROWID | LOG_DATA |  1000 |   217K|    13   (0)| 00:00:01 |                                                          
|*  5 |      INDEX RANGE SCAN DESCENDING| LOG_DATE |    11 |       |     2   (0)| 00:00:01 |                                                          
--------------------------------------------------------------------------------------------                                                          
                                                                                                                                                      
Predicate Information (identified by operation id):                                                                                                   
---------------------------------------------------                                                                                                   
                                                                                                                                                      
   1 - filter(ROWNUM<=10)                                                                                                                             
   3 - filter(ROWNUM<=10)                                                                                                                             
   5 - access("ACCOUNT_ID"=5 AND "LOG_TYPE"=2 AND                                                                                                     
              NLSSORT("SYS_NAME",'nls_sort=''BINARY_CI''')=HEXTORAW('6100') )                                                                         


Statistics
----------------------------------------------------------                                                                                            
          8  recursive calls                                                                                                                          
          0  db block gets                                                                                                                            
        981  consistent gets                                                                                                                          
          0  physical reads                                                                                                                           
          0  redo size                                                                                                                                
        923  bytes sent via SQL*Net to client                                                                                                         
        524  bytes received via SQL*Net from client                                                                                                   
          2  SQL*Net roundtrips to/from client                                                                                                        
          1  sorts (memory)                                                                                                                           
          0  sorts (disk)                                                                                                                             
         10  rows processed                                                                                                                           

SQL> 
SQL> set autotrace off
SQL> 

SQL> 
SQL> --
SQL> -- Now use dbms_xplan to generate the plan
SQL> --
SQL> SELECT /*+ gather_plan_statistics */
  2  	     *
  3  FROM
  4    (
  5  	 SELECT
  6  	     sys_name, log_time,  substr(msg,1,40) msg
  7  	 FROM log_data
  8  	 WHERE
  9  	   account_id=5
 10  	   AND log_type=2
 11  	   AND sys_name='a'
 12  	 ORDER BY
 13  	   log_time  desc
 14    )
 15  WHERE
 16    rownum 'allstats last'));

PLAN_TABLE_OUTPUT                                                                                                                                     
------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  36qykj7j9tsrp, child number 0                                                                                                                 
-------------------------------------                                                                                                                 
SELECT /*+ gather_plan_statistics */         * FROM   (     SELECT                                                                                    
   sys_name, log_time,  substr(msg,1,40) msg     FROM log_data                                                                                        
WHERE       account_id=5       AND log_type=2       AND sys_name='a'                                                                                  
 ORDER BY       log_time  desc   ) WHERE   rownum <= 10                                                                                               
                                                                                                                                                      
Plan hash value: 1444908817                                                                                                                           
                                                                                                                                                      
---------------------------------------------------------------------------------------------------------------------------------                     
| Id  | Operation                       | Name     | Starts | E-Rows | A-Rows |   A-Time   | Buffers |  OMem |  1Mem | Used-Mem |                     

PLAN_TABLE_OUTPUT                                                                                                                                     
------------------------------------------------------------------------------------------------------------------------------------------------------
---------------------------------------------------------------------------------------------------------------------------------                     
|   0 | SELECT STATEMENT                |          |      1 |        |     10 |00:00:00.01 |     979 |       |       |          |                     
|*  1 |  COUNT STOPKEY                  |          |      1 |        |     10 |00:00:00.01 |     979 |       |       |          |                     
|   2 |   VIEW                          |          |      1 |     11 |     10 |00:00:00.01 |     979 |       |       |          |                     
|*  3 |    SORT ORDER BY STOPKEY        |          |      1 |     11 |     10 |00:00:00.01 |     979 |  2048 |  2048 | 2048  (0)|                     
|   4 |     TABLE ACCESS BY INDEX ROWID | LOG_DATA |      1 |   1000 |    975 |00:00:00.01 |     979 |       |       |          |                     
|*  5 |      INDEX RANGE SCAN DESCENDING| LOG_DATE |      1 |     11 |    975 |00:00:00.01 |       5 |       |       |          |                     
---------------------------------------------------------------------------------------------------------------------------------                     
                                                                                                                                                      
Predicate Information (identified by operation id):                                                                                                   
---------------------------------------------------                                                                                                   

PLAN_TABLE_OUTPUT                                                                                                                                     
------------------------------------------------------------------------------------------------------------------------------------------------------
                                                                                                                                                      
   1 - filter(ROWNUM<=10)                                                                                                                             
   3 - filter(ROWNUM<=10)                                                                                                                             
   5 - access("ACCOUNT_ID"=5 AND "LOG_TYPE"=2 AND "LOG_DATA"."SYS_NC00006"=HEXTORAW('6100') )

 27 rows selected. SQL> 

Notice that both methods report the same execution plan; it’s the access predicates that differ, and autotrace reports the index as the access point rather than the hidden column in the table. Historically it’s been dbms_xplan.display_cursor that’s been the ‘truth’, but in this case it may be autotrace reporting the actual predicates in use.

And that’s the truth.

Create a free website or blog at WordPress.com.