CPU Wait? LAG to the Rescue

26 02 2010

February 26, 2010

A question in a recent OTN thread appeared as follows:

I’m in RAC database (10gR2/Redhat4). I need to store the real CPU wait every 1 minute in a table for a month. For that I thing to query the GV$SYS_TIME_MODEL [for the “DB CPU” statistic].

This is a very difficult question to answer.  Why (additional reference)?  Technically, in Oracle when a session is “on the CPU”, that session is not in a wait event, and therefore not officially waiting for anything. The “DB CPU” statistic captures the accumulated time spent on the CPU by foreground processes – the user sessions. This CPU time does not include the time that the background processes (DBWR, LGWR, PMON, etc.) spend consuming CPU time. Additionally, the “DB CPU” statistic does not consider/accumulate CPU time consumed by processes that are not related to the database instance.  It could also be said that the “DB CPU” time does not account for time that the session spends waiting for its turn to execute on the CPUs.

With the above in mind, let’s see if we are able to calculate the amount of CPU time consumed by the sessions and the background processes in one minute intervals.  First, we need a logging table.  The following SQL statement builds the SYS_TIME_MODEL_CPU table using a couple of the column definitions from the GV$SYS_TIME_MODEL view so that I do not need to explicitly state the column data types (notice that the SQL statement is collapsing data from two source rows into a single row):

CREATE TABLE SYS_TIME_MODEL_CPU AS
SELECT
  SYSDATE CHK_ID,
  INST_ID,
  SUM(DECODE(STAT_NAME,'DB CPU',VALUE,NULL)) DB_CPU,
  SUM(DECODE(STAT_NAME,'background cpu time',VALUE,NULL)) BACKGROUND_CPU
FROM
  GV$SYS_TIME_MODEL
WHERE
  0=1
GROUP BY
  INST_ID;

If we are able to find a way to schedule the following SQL statement to execute once a minute, we will be able to store the current values of the “DB CPU” and “background cpu time” statistics with the following SQL statement (note that executing this SQL statement will also consume CPU time, the very thing we are trying to measure):

INSERT INTO SYS_TIME_MODEL_CPU
SELECT
  SYSDATE CHK_ID,
  INST_ID,
  SUM(DECODE(STAT_NAME,'DB CPU',VALUE,NULL)) DB_CPU,
  SUM(DECODE(STAT_NAME,'background cpu time',VALUE,NULL)) BACKGROUND_CPU
FROM
  GV$SYS_TIME_MODEL
WHERE
  STAT_NAME IN ('DB CPU','background cpu time')
GROUP BY
  INST_ID;

One way to schedule the SQL statement to execute once a minute is to use the DBMS_LOCK.SLEEP function in a loop.  Unfortunely, on some platforms the function may not wait exactly the specified number of seconds (it may wait slightly longer), and may cause the “PL/SQL lock timer” wait event to steal a position in the top 5 wait events list in a Statspack or AWR report.  For testing purposes, the following anonymous PL/SQL script might be used:

DECLARE
  STime DATE := SYSDATE;
BEGIN
  WHILE (SYSDATE - STime) < 32 LOOP
    INSERT INTO SYS_TIME_MODEL_CPU
      SELECT
        SYSDATE CHK_ID,
        INST_ID,
        SUM(DECODE(STAT_NAME,'DB CPU',VALUE,NULL)) DB_CPU,
        SUM(DECODE(STAT_NAME,'background cpu time',VALUE,NULL)) BACKGROUND_CPU
      FROM
        GV$SYS_TIME_MODEL
      WHERE
        STAT_NAME IN ('DB CPU','background cpu time')
      GROUP BY
        INST_ID;

      COMMIT;
      DBMS_LOCK.SLEEP(60);
  End Loop;
End;
/

If we allow the script to run for a couple of minutes (rather than 31 days), we are able to determine how much CPU time was consumed every minute by using the LAG analytic function, as shown below:

SELECT
  TO_CHAR(CHK_ID,'YYYY-MM-DD HH24:MI') CHK_ID,
  INST_ID,
  DB_CPU-LAG(DB_CPU,1) OVER (PARTITION BY INST_ID ORDER BY CHK_ID) DB_CPU,
  BACKGROUND_CPU-LAG(BACKGROUND_CPU,1) OVER (PARTITION BY INST_ID ORDER BY CHK_ID) BACKGROUND_CPU
FROM
  SYS_TIME_MODEL_CPU
ORDER BY
  CHK_ID;

CHK_ID              INST_ID     DB_CPU BACKGROUND_CPU
---------------- ---------- ---------- --------------
2010-02-24 07:18          1
2010-02-24 07:19          1   59990544          66070
2010-02-24 07:20          1   59951475          66724
2010-02-24 07:21          1   59985268          71768
2010-02-24 07:22          1   60000569          63694
2010-02-24 07:23          1   60002938          71639
2010-02-24 07:24          1   59978651          63770
2010-02-24 07:25          1   61487141          62785
2010-02-24 07:26          1      24194          76990

To determine the number of seconds of CPU time consumed, the values shown in the DB_CPU and BACKGROUND_CPU columns should be divided by 1,000,000.

Why not just use AWR data to obtain this information?  Just because AWR is built-in does not mean that it is free to use the features of AWR (as I attempted to argue in this OTN thread) – this is a fact that is often glossed over by various books, blog articles, “news” articles, and even the Oracle Database documentation when it states that AWR reports are the replacement for Statspack reports.





Reviewing Session-Level Parameters

25 02 2010

February 25, 2010

A couple of days ago I received an email from a friend who manages a database (10.2.0.4) that is used by the same ERP platform as is used where I work.  The email was quite friendly until I saw the attached file, which included a rather unfriendly ORA-07445 error message and stack trace:

ksedmp: internal or fatal error
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [_intel_fast_memcpy.A+18] [PC:0x33CFC0E] [ADDR:0x39D10000] [UNABLE_TO_READ] []
Current SQL statement for this session:
update my_table set
costed_date = SYSDATE
where type = 'W'
and base_id = :1       
and lot_id = :2      
and split_id = :3        
and sub_id = '0' 

----- Call Stack Trace -----
calling              call     entry                argument values in hex     
location             type     point                (? means dubious value)    
-------------------- -------- -------------------- ----------------------------
_intel_fast_memcpy.           0000000000000000     000000000 000000000 000000000
A+18                                               000000000
0000000000000001     CALL???  _intel_fast_memcpy.  110F0E2E0 00118F111 0F7714C60
                              A+18                 1160CE740
0000000110F0E2E0     CALL???  0000000000000001     00118F111 0F7714C60 1160CE740
                                                   000000004
updgrh+3747          CALL???  0000000110F0E2E0     0F7714C60 1160CE740 000000004
                                                   000000000
__PGOSF480_upduaw+1  CALL???  updgrh+3747          11DEAD460 00001E768 000000000
58                                                 ACD6D33AF808
kdusru+540           CALL???  __PGOSF480_upduaw+1  00001E658 000000002 00001F2E0
                              58                   00001F430
kauupd+521           CALL???  kdusru+540           110F0DBC0 023037F78 000000000
                                                   000000000
updrow+2086          CALL???  kauupd+521           039CDBA10 110F0DA48 039D0E000
                                                   100000000
__PGOSF536_qerupRow  CALL???  updrow+2086          110E03438 000007FFF 002E4644C
Procedure+93                                       00001F430
qerupFetch+748       CALL???  __PGOSF536_qerupRow  0EB37C530 000000000 000000000
                              Procedure+93         100000000
...

No wonder it crashed with an ORA-07445 Access Violation error – look at the first argument of the __PGOSF480_upduaw+158 calling location – it must be that fatal errors appear in Oracle whenever the hexadecimal number DEAD appears in the middle of an argument. 🙂  (Watch out for false correlation when troubleshooting.)  In case you are wondering, Metalink Doc ID 175982.1 “ORA-600 Lookup Error Categories” does not describe the updgrh function that eventually lead to the crash in the _intel_fast_memcpy.A+18 calling location, but there are a couple of articles on Metalink that describe updgrh as a function that is involved in updates to migrated rows.

As an experiment, a logon trigger like the following was created (caution, this logon trigger changes a “hidden” Oracle parameter to disable bind variable peeking – exercise caution, and check with Oracle support, before changing any hidden parameters):

CREATE OR REPLACE TRIGGER "SYS"."NO_PEEK_BIND" AFTER LOGON ON DATABASE
DECLARE
  SHOULD_EXECUTE INTEGER;
BEGIN
  SELECT DECODE(SUBSTR(UPPER(PROGRAM),1,8),'AAAAAAAA',1,0)+DECODE(INSTR(PROGRAM,'\',-1),0,0,DECODE(SUBSTR(UPPER(SUBSTR(PROGRAM,INSTR(PROGRAM,'\',-1)+1)),1,8),'AAAAAAAA',1,0)) INTO SHOULD_EXECUTE FROM V$SESSION WHERE SID=(SELECT SID FROM V$MYSTAT WHERE ROWNUM=1);
  IF SHOULD_EXECUTE > 0 THEN
    EXECUTE IMMEDIATE 'ALTER SESSION SET "_optim_peek_user_binds"=FALSE';
  END IF;
END;
/

The above logon trigger disables bind variable peeking for any program with AAAAAAAA at the start of its filename, even if a portion of the program’s file path (assuming that the path directories are separated by backslashes) is included in the PROGRAM column of V$SESSION.  Once in place, this logon trigger changes the parsing environment for the session such that any previously hard parsed SQL statements that were used by the program in the past would need to be re-hard parsed when executed by the program.  Looking through the remainder of the trace file I noticed that a lot of the bind variables were not set to a value (No bind buffers allocated appeared in the trace file) during the first parse call by the session, so peeking at the bind variables could potentially cause problems if that special case is not handled correctly by Oracle Database 10.2.0.4.  (The stack trace did not suggest that bind variable peeking was the cause of the problem.)

Once the trigger was in place, and new sessions have connected, were are able to confirm that the session-level parameter modification happened with the following SQL statement:

SELECT
  S.SID,
  SUBSTR(S.PROGRAM,1,8) PROGRAM,
  SOE.NAME,
  SOE.VALUE,
  SOE.ISDEFAULT
FROM
  V$SESSION S,
  V$SES_OPTIMIZER_ENV SOE
WHERE
  SUBSTR(UPPER(S.PROGRAM),1,8) IN ('AAAAAAAA','BBBBBBBB')
  AND S.SID=SOE.SID
ORDER BY
  NAME,
  PROGRAM;

 SID PROGRAM  NAME                                 VALUE                     ISD
---- -------- ------------------------------------ ------------------------- ---
 303 AAAAAAAA _optim_peek_user_binds               false                     NO
 303 AAAAAAAA _optimizer_adaptive_cursor_sharing   false                     NO
 335 BBBBBBBB _optimizer_adaptive_cursor_sharing   false                     NO
 303 AAAAAAAA active_instance_count                1                         YES
 335 BBBBBBBB active_instance_count                1                         YES
 303 AAAAAAAA bitmap_merge_area_size               1048576                   YES
 335 BBBBBBBB bitmap_merge_area_size               1048576                   YES
 303 AAAAAAAA cell_offload_compaction              ADAPTIVE                  YES
 335 BBBBBBBB cell_offload_compaction              ADAPTIVE                  YES
 303 AAAAAAAA cell_offload_plan_display            AUTO                      YES
 335 BBBBBBBB cell_offload_plan_display            AUTO                      YES
 303 AAAAAAAA cell_offload_processing              true                      YES
 335 BBBBBBBB cell_offload_processing              true                      YES
 303 AAAAAAAA cpu_count                            2                         YES
 335 BBBBBBBB cpu_count                            2                         YES
 303 AAAAAAAA cursor_sharing                       exact                     YES
 335 BBBBBBBB cursor_sharing                       exact                     YES
 303 AAAAAAAA db_file_multiblock_read_count        32                        YES
 335 BBBBBBBB db_file_multiblock_read_count        32                        YES
 303 AAAAAAAA hash_area_size                       131072                    YES
 335 BBBBBBBB hash_area_size                       131072                    YES
 303 AAAAAAAA is_recur_flags                       0                         YES
 335 BBBBBBBB is_recur_flags                       0                         YES
 303 AAAAAAAA optimizer_capture_sql_plan_baselines false                     YES
 335 BBBBBBBB optimizer_capture_sql_plan_baselines false                     YES
 303 AAAAAAAA optimizer_dynamic_sampling           2                         YES
 335 BBBBBBBB optimizer_dynamic_sampling           2                         YES
 303 AAAAAAAA optimizer_features_enable            11.1.0.7                  YES
 335 BBBBBBBB optimizer_features_enable            11.1.0.7                  YES
 303 AAAAAAAA optimizer_index_caching              0                         YES
 335 BBBBBBBB optimizer_index_caching              0                         YES
 303 AAAAAAAA optimizer_index_cost_adj             100                       YES
 335 BBBBBBBB optimizer_index_cost_adj             100                       YES
 303 AAAAAAAA optimizer_mode                       all_rows                  YES
 335 BBBBBBBB optimizer_mode                       all_rows                  YES
 303 AAAAAAAA optimizer_secure_view_merging        true                      YES
 335 BBBBBBBB optimizer_secure_view_merging        true                      YES
 303 AAAAAAAA optimizer_use_invisible_indexes      false                     YES
 335 BBBBBBBB optimizer_use_invisible_indexes      false                     YES
 303 AAAAAAAA optimizer_use_pending_statistics     false                     YES
 335 BBBBBBBB optimizer_use_pending_statistics     false                     YES
 303 AAAAAAAA optimizer_use_sql_plan_baselines     true                      YES
 335 BBBBBBBB optimizer_use_sql_plan_baselines     true                      YES
 303 AAAAAAAA parallel_ddl_mode                    enabled                   YES
 335 BBBBBBBB parallel_ddl_mode                    enabled                   YES
 303 AAAAAAAA parallel_degree                      0                         YES
 335 BBBBBBBB parallel_degree                      0                         YES
 303 AAAAAAAA parallel_dml_mode                    disabled                  YES
 335 BBBBBBBB parallel_dml_mode                    disabled                  YES
 303 AAAAAAAA parallel_execution_enabled           false                     YES
 335 BBBBBBBB parallel_execution_enabled           false                     YES
 303 AAAAAAAA parallel_query_default_dop           0                         YES
 335 BBBBBBBB parallel_query_default_dop           0                         YES
 303 AAAAAAAA parallel_query_mode                  enabled                   YES
 335 BBBBBBBB parallel_query_mode                  enabled                   YES
 303 AAAAAAAA parallel_threads_per_cpu             2                         YES
 335 BBBBBBBB parallel_threads_per_cpu             2                         YES
 303 AAAAAAAA pga_aggregate_target                 143360 KB                 YES
 335 BBBBBBBB pga_aggregate_target                 143360 KB                 YES
 303 AAAAAAAA query_rewrite_enabled                true                      YES
 335 BBBBBBBB query_rewrite_enabled                true                      YES
 303 AAAAAAAA query_rewrite_integrity              enforced                  YES
 335 BBBBBBBB query_rewrite_integrity              enforced                  YES
 303 AAAAAAAA result_cache_mode                    MANUAL                    YES
 335 BBBBBBBB result_cache_mode                    MANUAL                    YES
 303 AAAAAAAA skip_unusable_indexes                true                      YES
 335 BBBBBBBB skip_unusable_indexes                true                      YES
 303 AAAAAAAA sort_area_retained_size              0                         YES
 335 BBBBBBBB sort_area_retained_size              0                         YES
 303 AAAAAAAA sort_area_size                       65536                     YES
 335 BBBBBBBB sort_area_size                       65536                     YES
 303 AAAAAAAA star_transformation_enabled          false                     YES
 335 BBBBBBBB star_transformation_enabled          false                     YES
 303 AAAAAAAA statistics_level                     typical                   YES
 335 BBBBBBBB statistics_level                     typical                   YES
 303 AAAAAAAA transaction_isolation_level          read_commited             YES
 335 BBBBBBBB transaction_isolation_level          read_commited             YES
 303 AAAAAAAA workarea_size_policy                 auto                      YES
 335 BBBBBBBB workarea_size_policy                 auto                      YES

The above output is obviously not from the 10.2.0.4 database.  As can be determined by the above, the _OPTIM_PEEK_USER_BINDS parameter is set to FALSE only for the program AAAAAAAA.  If you look closely at the output, you will also notice that the _OPTIMIZER_ADAPTIVE_CURSOR_SHARING parameter is set to the non-default value of FALSE for both sessions (this change was made in the spfile), and it would be a logical next step to determine why that hidden parameter was changed from the default.

Did changing the behavior of bind variable peeking solve the ORA-07445 Access Violation error?  Well, that question is off topic for this blog article – the ORA-07445 is just one reason why it might be necessary to explore the parameters that were modified at the session-level.  V$SES_OPTIMIZER_ENV shows the parameters that were modified from the Oracle defaults (check the ISDEFAULT column) at the session-level, and those values may be compared with the system-wide defaults found in the V$SYS_OPTIMIZER_ENV view.  A previous blog article described the V$SQL_OPTIMIZER_ENV view, which shows the parameters that were in effect when a specific child cursor was initially hard parsed.





Eliminating 2 Wait Events from the Top 5, How Many Remain?

24 02 2010

February 24, 2010

A recent question on the OTN forums forced me to stop and think for a moment.  If you eliminate two of the most commonly found wait events from the top five wait events:

  • How many wait events will appear in the top five wait events for a selected time period (hint – something has to appear in the top five)?
  • When the two most commonly found wait events are eliminated from the top five, does that necessarily mean that the database performance is better, or could the performance be worse?

The question from the OTN forum is as follows:

I have a query regarding the 2 events:
1. db file scattered read
2. db file sequential read

If the above two events are in top 5 events then what could be the reason for this and how to resolve the issue?

The question asked is a good question, but something is missing.  Similar questions have appeared on various forums in the past, so this blog article is not specifically addressed to this particular OTN posting.  The original poster excluded a couple of potentially useful pieces of information:

  • What Oracle release and operating system platform is in use?
  • How many seconds of wait time were reported in each of the wait events?
  • What was the total duration of the statistics collection period?
  • Were there any other, potentially more significant wait events in the top five list?
  • How many users were connected to the database?
  • What was the average wait duration for each of the events, and how many waits?
  • Were any business critical processes operating at a slower than expected speed?

There will always be five wait events in a top 5 list, so if the original poster was able to somehow eliminate those datafile type access waits events from the top 5 list, which wait events should take the place of the db file scattered read and db file sequential read waits?  Would it be better to see a different set of wait events, maybe pipe get and inactive session followed closely by cleanup of aborted processes? (I think that there might be a play on words and their definitions here – SHUTDOWN IMMEDIATE; is one certain way to decrease the frequency of datafile type access waits.)





Retrieving the Hidden Oracle Parameters and Saving the Parameter Values in Excel

23 02 2010

February 23, 2010

The are a large number of initialization parameters that configure the behavior of an Oracle database instance, and it seems that the number of hidden parameters (those parameters that begin with _ ) continues to grow with each new Oracle Database release.  In some cases, parameters that were once normal parameters became hidden parameters in later releases (the SPIN_COUNT, and _SPIN_COUNT parameters are one example).  In other cases, the normal parameter defines the minimum requested parameter value and the hidden parameter defines the current value (DB_CACHE_SIZE and __DB_CACHE_SIZE parameters, respectively).

For documentation purposes it might be helpful to permanently record the values of the normal and hidden initialization parameters, and that is the purpose of the VBS script in this article.  The script uses a SQL statement that was originally found here, and then was modified so that the normal and hidden versions of the parameters will sort into adjacent rows when dislayed on screen.  Once the parameter values are written to Excel, the Excel worksheet is automatically saved with the value of the DB_NAME initialization parameter and the current date and time.  When targeting an 11.2.0.1 database, the output might look like the following screen capture:

Unfortunately, we have a slight problem.  The SQL statement in the script must be executed as the SYS user, and if the O7_DICTIONARY_ACCESSIBILITY initialization parameter is set to FALSE (the default starting with Oracle 9.0.1), the normal connection string used in previous scripts will not work (I have not found a way to pass AS SYSDBA when Provider=OraOLEDB.Oracle is specified in the connection string).  If you do not want to set the O7_DICTIONARY_ACCESSIBILITY initialization parameter to TRUE, you will need to create an ODBC connection to the database.

To create an ODBC connection, launch the ODBC Data Source Administrator utility from the Control Panel, and switch to the System DSN tab.  Click Add… then select one of the ODBC providers offered by Oracle Corp (you may need to perform a custom install of the Oracle Client for Oracle’s ODBC client to appear in the list – note that there is a separate 32 bit and 64 bit ODBC Administrator on 64 bit Windows, with the 32 bit version located in the Windows\SysWow64 folder, see this article for more information):

Pick a generic name for the ODBC connection, such as MyODBC (this is the name used in the script) and then enter the database name from the Tnsnames.ora file into the TNS Service Name box (I specified or112) – note that you can change this database name at a later time to point the script at a different database.  Click OK.

The VBS script to extract the normal and hidden parameters follows (modify the script to specify the correct password for the SYS user):

'Version 1.0

Const adCmdText = 1
Const adCmdStoredProc = 4
Const adParamInput = 1
Const adVarNumeric = 139
Const adBigInt = 20
Const adDecimal = 14
Const adDouble = 5
Const adInteger = 3
Const adLongVarBinary = 205
Const adNumeric = 131
Const adSingle = 4
Const adSmallInt = 2
Const adTinyInt = 16
Const adUnsignedBigInt = 21
Const adUnsignedInt = 19
Const adUnsignedSmallInt = 18
Const adUnsignedTinyInt = 17
Const adDate = 7
Const adDBDate = 133
Const adDBTimeStamp = 135
Const adDBTime = 134
Const adVarChar = 200
Const adUseClient = 3

Dim strUsername
Dim strPassword
Dim strDatabase
Dim strSQL                          'SQL statement
Dim objExcel                        'For sending the output to Excel

Dim snpData                         'ADO Recordset object used to retrieve the user's data
Dim dbDatabase                      'ADO database connection object

Dim intTempCount                    'Counter of the number of Excel sheets that have been created

Dim strDBNAME                       'DB_NAME parameter from the database parameters
Dim strLastColumn                   'Column identifier in Excel of the right-most column

Dim i                               'Counter

On Error Resume Next

Set snpData = CreateObject("ADODB.Recordset")
Set dbDatabase = CreateObject("ADODB.Connection")

'Create an Excel connection
Set objExcel = CreateObject("Excel.Application")

'Set up to allow exporting, if requested
objExcel.DisplayAlerts = False
objExcel.Workbooks.Add

strUsername = "sys"    'Must connect as the SYS user
strPassword = "SysPassword"
strDatabase = "MyODBC" 'Must use an ODBC connection if O7_DICTIONARY_ACCESSIBILITY = FALSE

If UCase(strUsername) <> "SYS" Then
  'Can use this for SYS if O7_DICTIONARY_ACCESSIBILITY = TRUE, ODBC connection then not required
  dbDatabase.ConnectionString = "Provider=OraOLEDB.Oracle;Data Source=" & strDatabase & ";User ID=" & strUsername & ";Password=" & strPassword & ";"
Else
  'Must use an ODBC connection if O7_DICTIONARY_ACCESSIBILITY = FALSE
  dbDatabase.ConnectionString = "Data Source=" & strDatabase & ";User ID=" & strUsername & ";Password=" & strPassword & " AS SYSDBA;"
End If

dbDatabase.Open

'Should verify that the connection attempt was successful, but I will leave that for someone else to code
If Err <> 0 Then
  MsgBox "Not Connected, Error: " & Err
Else
  'Adapted from the SQL statement at http://www.jlcomp.demon.co.uk/params.html
  strSQL = "SELECT " & vbCrLf
  strSQL = strSQL & "  UPPER(NAM.KSPPINM) NAME," & vbCrLf
  strSQL = strSQL & "  VAL.KSPPSTVL VALUE," & vbCrLf
  strSQL = strSQL & "  NAM.INDX+1 NUM," & vbCrLf
  strSQL = strSQL & "  NAM.KSPPITY TYPE," & vbCrLf
  strSQL = strSQL & "  VAL.KSPPSTDF ISDEFAULT," & vbCrLf
  strSQL = strSQL & "  DECODE(BITAND(NAM.KSPPIFLG/256,1),1,'TRUE','FALSE') ISSES_MODIFIABLE," & vbCrLf
  strSQL = strSQL & "  DECODE(BITAND(NAM.KSPPIFLG/65536,3)," & vbCrLf
  strSQL = strSQL & "    1,'IMMEDIATE'," & vbCrLf
  strSQL = strSQL & "    2,'DEFERRED' ," & vbCrLf
  strSQL = strSQL & "    3,'IMMEDIATE'," & vbCrLf
  strSQL = strSQL & "    'FALSE') ISSYS_MODIFIABLE," & vbCrLf
  strSQL = strSQL & "  DECODE(BITAND(VAL.KSPPSTVF,7)," & vbCrLf
  strSQL = strSQL & "    1,'MODIFIED'," & vbCrLf
  strSQL = strSQL & "    4,'SYSTEM MODIFIED'," & vbCrLf
  strSQL = strSQL & "    'FALSE') ISMODIFIED," & vbCrLf
  strSQL = strSQL & "  DECODE(BITAND(VAL.KSPPSTVF,2),2,'TRUE', 'FALSE') ISADJUSTED," & vbCrLf
  strSQL = strSQL & "  NAM.KSPPDESC DESCRIPTION" & vbCrLf
  strSQL = strSQL & "FROM" & vbCrLf
  strSQL = strSQL & "  X$KSPPI NAM," & vbCrLf
  strSQL = strSQL & "  X$KSPPSV VAL" & vbCrLf
  strSQL = strSQL & "WHERE " & vbCrLf
  strSQL = strSQL & "  NAM.INDX = VAL.INDX " & vbCrLf
  strSQL = strSQL & "ORDER BY" & vbCrLf
  strSQL = strSQL & "  UPPER(DECODE(SUBSTR(NAM.KSPPINM,1,2),'__',SUBSTR(NAM.KSPPINM,3)," & vbCrLf
  strSQL = strSQL & "          DECODE(SUBSTR(NAM.KSPPINM,1,1),'_',SUBSTR(NAM.KSPPINM,2),NAM.KSPPINM)))," & vbCrLf
  strSQL = strSQL & "  UPPER(NAM.KSPPINM)"
  snpData.Open strSQL, dbDatabase

  If snpData.State = 1 Then
    If Not (snpData.EOF) Then
      With objExcel
        .Visible = True
        .ActiveWorkbook.Sheets.Add
        .ActiveSheet.Name = "DB Parameters"

         For i = 0 To snpData.Fields.Count - 1
           .ActiveSheet.Cells(1, i + 1).Value = snpData.Fields(i).Name
         Next
         .ActiveSheet.Range(.ActiveSheet.Cells(1, 1), .ActiveSheet.Cells(1, snpData.Fields.Count)).Font.Bold = True

         'Format the columns in the spreadsheet
         For i = 0 To snpData.Fields.Count - 1
           strLastColumn = Chr(64 + ((i + 1) Mod 26))

           .Columns(strLastColumn).Select
           Select Case snpData.Fields(i).Type
             Case adDate, adDBDate, adDBTimeStamp, adDBTime
               .Selection.HorizontalAlignment = -4152
               .Selection.NumberFormat = "mm/dd/yy hh:nn AM/PM"
             Case adBigInt, adInteger, adSmallInt, adTinyInt, adUnsignedBigInt, adUnsignedInt, adUnsignedSmallInt, adUnsignedTinyInt
               .Selection.HorizontalAlignment = -4152
               .Selection.NumberFormat = "0"
             Case adVarNumeric, adDecimal, adDouble, adNumeric, adSingle
               .Selection.HorizontalAlignment = -4152
               .Selection.NumberFormat = "0"
             Case adVarChar
               .Selection.HorizontalAlignment = -4131
               .Selection.NumberFormat = "@"
           End Select
         Next

         strLastColumn = Chr(64 + ((snpData.Fields.Count + 1) Mod 26))
         .ActiveSheet.Range("A2").CopyFromRecordset snpData

         'Auto-fit up to columns
         .ActiveSheet.Columns("A:" & strLastColumn).AutoFit
         .ActiveSheet.Range("B2").Select
         .ActiveWindow.FreezePanes = True

         .Application.DisplayAlerts = False
         'Remove the default worksheets
         For i = 1 To ActiveWorkbook.Sheets.Count
           If .ActiveWorkbook.Sheets(i).Name = "Sheet1" Then
             .Sheets("Sheet1").Select
             .ActiveWindow.SelectedSheets.Delete
           End If
           If .ActiveWorkbook.Sheets(i).Name = "Sheet2" Then
             .Sheets("Sheet2").Select
             .ActiveWindow.SelectedSheets.Delete
           End If
           If .ActiveWorkbook.Sheets(i).Name = "Sheet3" Then
             .Sheets("Sheet3").Select
             .ActiveWindow.SelectedSheets.Delete
           End If
         Next
      End With
      snpData.Close

      'Repeat the SQL statement to find the value of the DB_NAME parameter
      snpData.Open strSQL, dbDatabase

      Do While Not (snpData.EOF)
        If UCase(snpData("name")) = "DB_NAME" Then
          strDBNAME = snpData("value")
          Exit Do
        End If
        snpData.MoveNext
      Loop
    Else
      MsgBox "No Rows Returned"
    End If
  Else
    MsgBox "Could Not Open the SQL Statement " & Err
  End If
  snpData.Close

  objExcel.ActiveWorkbook.SaveAs "C:\OracleParameters " & strDBNAME & " " & Replace(Replace(Now, "/", "-"), ":", "-") & ".xls"
End If

'Clean Up
Set objExcel = Nothing
Set snpData = Nothing
dbDatabase.Close
Set dbDatabase = Nothing

When the script runs it will create a spreadsheet in the root of the C:\ drive – move the spreadsheet as needed for documentation purposes.





CPU Usage Monitoring – What are the Statistics and when are the Statistics Updated?

22 02 2010

February 22, 2010 (Updated March 7, 2010, August 10, 2010)

As mentioned in Chapter 8 of the “Expert Oracle Practices” book, there are several ways to measure the amount of CPU time used, whether at the operating system level, at the instance-wide level, at the session level, or at the SQL statement level.  In a previous blog article I described why driving the database server’s CPUs to 100% utilization was a bad idea and provided quotes from several articles that disagreed as well as several that agreed with my statements (Cary Millsap’s follow-up comment should be read carefully).

I mentioned in the previous blog article that some CPUs will slow their core frequences if thermal thresholds are reached, which might be possible by pegging the CPU at 100% utilization for long periods of time.  Intel offers the Intel Processor Identification Utility for the Windows platform (similar utilities for other platforms and non-Intel processors probably also exist) that shows the rated processor speed and the current CPU speed for each CPU/core in the server.  For example, the following is the output from the Intel program when run on my three year old laptop:

Here is the same laptop, captured in a different time period.  This particular slow down was not caused by a thermal threshold problem, rather it was created by setting the Windows power plan to Power Saver:

In the above, notice that the reported core speed for both CPU cores is 50% of the expected CPU speed, and even the system bus speed dropped slightly (I have seen lower CPU speeds and system bus speeds when the computer wakes from hibernation mode).  (Edit: See the pictures at the end of the article for examples of slower speeds 8+ hours after coming out of hibernation mode.)

Let’s jump into Oracle now (we will use Oracle Database 11.2.0.1 and 11.1.0.6).  There are several statistics in the database views that report CPU utilization.  One such statistic is CPU used by this session.  This is a potentially challenging statistic to use.  From the documentation:

CPU used by this session: Amount of CPU time (in 10s of milliseconds) used by a session from the time a user call starts until it ends. If a user call completes within 10 milliseconds, the start and end user-call time are the same for purposes of this statistics, and 0 milliseconds are added. A similar problem can exist in the reporting by the operating system, especially on systems that suffer from many context switches.

CPU used when call started: The CPU time used when the call is started

If we try to understand the above, the CPU used by this session statistic is the time, in centiseconds, of CPU utilization while a user call is running on the server’s CPUs.  The second statistic, CPU used when call started, indicates the value of the CPU used by this session statistic when the user call was started.  The documentation leaves a couple of questions unanswered:

  • When are these statistics updated?  If the CPU used by this session statistic is updated in real-time (if you are wondering, it is Not), the CPU used when call started statistic could be used to determine how long the session has been on the CPU (and not in a wait event and not in one of the other CPU run states), but if the statistics are not updated in real time, what is the point of having two separate statistics?
  • What is considered a user call – is it the full execution of a user’s SQL statement, or is it a fetch of a block from disk, or is it the completion of a fetch of some of the result rows, or is a user call something entirely different?

We need a test case to see what is happening with these statistics, and several of the other statistics that measure CPU utilization (warning, this test table may take an hour or longer to create).

CREATE TABLE T1 (
  ID NUMBER,
  DESCRIPTION VARCHAR2(80));

INSERT INTO T1
SELECT
  CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),
  'This is the long description for this number '|| TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000)))
FROM
  (SELECT
    ROWNUM RN
  FROM
    DUAL
  CONNECT BY
    LEVEL<=10000),
  (SELECT
    ROWNUM RN
  FROM
    DUAL
  CONNECT BY
    LEVEL<=10000);

COMMIT;

CREATE INDEX IND_T1 ON T1(ID);

EXEC DBMS_STATS.GATHER_TABLE_STATS(OWNNAME=>USER,TABNAME=>'T1',CASCADE=>TRUE, METHOD_OPT=>'FOR ALL COLUMNS SIZE 1')

Once the test table is created, disconnect from the database and then reconnect to the database to reset the session-level statistic values.  Note that this test is performed with the FILESYSTEMIO_OPTIONS parameter set to SETALL to enable direct, asychronous I/O.  Next let’s determine the SID for the session:

SELECT
  SID
FROM
  V$MYSTAT
WHERE
  ROWNUM=1;

 SID
----
 552

Start up a second SQL*Plus connection to the database, and prepare to execute the following script (documentation references: V$OSSTAT, V$SESS_TIME_MODEL, V$SESSTAT):

SPOOL CPU_STATS.TXT
SET PAGESIZE 2000
SET ARRAYSIZE 1000

SELECT
  STAT_NAME,
  VALUE
FROM
  V$OSSTAT
WHERE
  STAT_NAME IN ('SYS_TIME','USER_TIME','BUSY_TIME','IDLE_TIME','IOWAIT_TIME','NICE_TIME','RSRC_MGR_CPU_WAIT_TIME')
ORDER BY
  STAT_NAME;

SELECT
  STAT_NAME,
  VALUE
FROM
  V$SESS_TIME_MODEL
WHERE
  STAT_NAME='DB CPU'
  AND SID=552
ORDER BY
  STAT_NAME;

SELECT
  SN.NAME,
  SS.VALUE
FROM
  V$SESSTAT SS,
  V$STATNAME SN
WHERE
  SS.SID=552
  AND SS.STATISTIC#=SN.STATISTIC#
  AND (SN.NAME LIKE 'CPU%'
       OR SN.NAME LIKE '%cpu%'
       OR SN.NAME LIKE '%consistent%')
ORDER BY
  SN.NAME;

host sleep 60

SELECT
  STAT_NAME,
  VALUE
FROM
  V$OSSTAT
WHERE
  STAT_NAME IN ('SYS_TIME','USER_TIME','BUSY_TIME','IDLE_TIME','IOWAIT_TIME','NICE_TIME','RSRC_MGR_CPU_WAIT_TIME')
ORDER BY
  STAT_NAME;

SELECT
  STAT_NAME,
  VALUE
FROM
  V$SESS_TIME_MODEL
WHERE
  STAT_NAME='DB CPU'
  AND SID=552
ORDER BY
  STAT_NAME;

SELECT
  SN.NAME,
  SS.VALUE
FROM
  V$SESSTAT SS,
  V$STATNAME SN
WHERE
  SS.SID=552
  AND SS.STATISTIC#=SN.STATISTIC#
  AND (SN.NAME LIKE 'CPU%'
       OR SN.NAME LIKE '%cpu%'
       OR SN.NAME LIKE '%consistent%')
ORDER BY
  SN.NAME;

host sleep 60

...

SPOOL OFF

In the above script, repeat the three SQL statements (replacing 552 with the SID number returned by your query) between sets of host sleep 60 calls as frequently as required, possibly 30 times, so that the full run of the SQL statement that will be executed by the first session is captured (see page 213 of the “Expert Oracle Practices” book for a Windows equivalent of the Unix/Linux sleep command) .

In the first session, prepare to execute the following script:

SET AUTOTRACE TRACEONLY STATISTICS
SET ARRAYSIZE 1000

SELECT /*+ INDEX(T1) */
  ID,
  DESCRIPTION
FROM
  T1
WHERE
  ID BETWEEN 1 AND 20;

The index hint is added in the above just to make certain that the IND_T1 index is used when we select 1.27% of the rows from the test table.  Start the monitoring script in the second session and immediately start the above script in the first session. 

When the first session completes, it should output something like the following (from the 11.2.0.1 test):

127325 rows selected.

Statistics
---------------------------------------------------
          1  recursive calls
          0  db block gets
     127794  consistent gets
     121986  physical reads
          0  redo size
    7084492  bytes sent via SQL*Net to client
       1757  bytes received via SQL*Net from client
        129  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
     127325  rows processed

Or the output might look something like the following (from the 11.1.0.6 test):

127325 rows selected.

Statistics
---------------------------------------------------
        154  recursive calls
          0  db block gets
     127727  consistent gets
     129179  physical reads
          0  redo size
    7084492  bytes sent via SQL*Net to client
       1757  bytes received via SQL*Net from client
        129  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
     127325  rows processed

If we take the spool file output that was generated by the second session and calculate the delta values for the statistics, we find the following statistic deltas were captured during each 60 second time period for the 11.2.0.1 test run:

STAT_NAME                                                        1        2        3        4        5        6        7        8        9       10
------------------------------------------------------    -------- -------- -------- -------- -------- -------- -------- -------- -------- --------
IDLE_TIME                                                   48,854   48,753   48,672   48,645   47,920   47,666   48,425   48,652   48,648   48,664
BUSY_TIME                                                      151      147      155      160      896    1,158      426      172      177      162
USER_TIME                                                       29       21       29       32      731    1,001      285       43       48       53
SYS_TIME                                                        55       55       57       54       96       91       69       58       57       49
IOWAIT_TIME                                                  5,825    6,002    5,980    5,978    6,317    6,394    6,087    6,017    6,007    4,750
NICE_TIME                                                        0        0        0        0        0        0        0        0        0        0
RSRC_MGR_CPU_WAIT_TIME                                           0        0        0        0        0        0        0        0        0        0

DB CPU                                                     483,927  485,925  503,924  525,920  471,928  357,946  443,932  462,930  460,930  369,943

CPU used when call started                                      48       45       52       51       48       37       44       47       45       35
CPU used by this session                                        48       45       52       51       48       37       44       47       45       38
parse time cpu                                                   0        0        0        0        0        0        0        0        0        0
recursive cpu usage                                              0        0        0        0        0        0        0        0        0        0
consistent gets                                             13,379   13,659   13,767   14,343   11,657    9,834   12,945   13,666   13,714   10,830
consistent gets from cache                                  13,379   13,659   13,767   14,343   11,657    9,834   12,945   13,666   13,714   10,830
no work - consistent read gets                              13,377   13,659   13,767   14,343   11,657    9,834   12,945   13,666   13,714   10,830
consistent gets from cache (fastpath)                          692      602      622      707      448      442      574      587      569      564
consistent gets - examination                                    2        0        0        0        0        0        0        0        0        0
consistent gets direct                                           0        0        0        0        0        0        0        0        0        0
consistent changes                                               0        0        0        0        0        0        0        0        0        0
transaction tables consistent reads - undo records applied       0        0        0        0        0        0        0        0        0        0
transaction tables consistent read rollbacks                     0        0        0        0        0        0        0        0        0        0
data blocks consistent reads - undo records applied              0        0        0        0        0        0        0        0        0        0
cleanouts only - consistent read gets                            0        0        0        0        0        0        0        0        0        0
rollbacks only - consistent read gets                            0        0        0        0        0        0        0        0        0        0
cleanouts and rollbacks - consistent read gets                   0        0        0        0        0        0        0        0        0        0

The 11.1.0.6 test run (executed after the 11.2.0.1 run completed without shutting down the 11.2.0.1 instance that was running on the same server) showed the following statistics:

STAT_NAME                                                        1        2        3        4
------------------------------------------------------    -------- -------- -------- --------
IDLE_TIME                                                   48,470   48,536   48,547   48,568
BUSY_TIME                                                      593      293      274      236
USER_TIME                                                      345       47       42       35
SYS_TIME                                                       117       87       83       59
IOWAIT_TIME                                                  6,394    5,878    5,887    5,460
NICE_TIME                                                        0        0        0        0
RSRC_MGR_CPU_WAIT_TIME                                           0        0        0        0

DB CPU                                                     669,899  862,868  845,872  671,898

CPU used when call started                                      68       86       82       67
CPU used by this session                                        68       86       82       68
parse time cpu                                                   2        0        0        0
recursive cpu usage                                              1        0        0        0
consistent gets                                             24,985   35,023   35,024   32,699
consistent gets from cache                                  24,985   35,023   35,024   32,699
no work - consistent read gets                              24,972   35,023   35,024   32,699
consistent gets from cache (fastpath)                       24,296   34,076   34,067   31,802
consistent gets - examination                                   13        0        0        0
consistent gets direct                                           0        0        0        0
consistent changes                                               0        0        0        0
transaction tables consistent reads - undo records applied       0        0        0        0
transaction tables consistent read rollbacks                     0        0        0        0
data blocks consistent reads - undo records applied              0        0        0        0
cleanouts only - consistent read gets                            0        0        0        0
rollbacks only - consistent read gets                            0        0        0        0
cleanouts and rollbacks - consistent read gets                   0        0        0        0

As evidenced by the above, the SQL statement completed in just less than 10 minutes in Oracle 11.2.0.1, while the SQL statement in 11.1.0.6 completed in just less than 4 minutes.  Why the significant time difference?  Maybe the above stats provide a clue?

The IDLE_TIME and BUSY_TIME statistics are server-wide with each of the server’s CPUs accumulating one second for every second of elapsed time, with the one second split between these two statistics.  USER_TIME is a server-wide statistic that indicates how many CPU centiseconds were spent executing application/Oracle level activity.  SYS_TIME is a server-wide statistic that indicates how many CPU centiseconds were spent executing operating system code (in kernel mode), typically on behalf of another program that usually accumulates CPU consumption time in the USER_TIME statistic.  In the above, DB CPU is accumulated at the session level and must be divided by 1,000,000 to convert the values to seconds.  The CPU used when call started and CPU used by this session statistics are at the session level and are reported in centiseconds.  If we look at the first time period for the Oracle 11.1.0.6 execution, we are able to derive the following statistics:

  • (48,470 idle centiseconds + 593 busy centiseconds) / (8 CPUs)  = 6132.875 centiseconds = 61.33 seconds in the time period
  • (593 / 100) = CPUs were used for 5.93 seconds of a total possible (61.33 * 8 ) CPU seconds in the time period
  • (593 busy centiseconds) / (48,470 idle centiseconds + 593 busy centiseconds) * 100 = CPUs were 1.21% busy
  • (345 user mode centiseconds) / (345 user mode centiseconds + 117 kernel mode centiseconds) * 100 = 74.68% of the CPU time was consumed in user mode
  • (669,899 / 1,000,000) = Monitored session consumed 0.6699 seconds of CPU time in the 61.33 second time period
  • (669,899 / 1,000,000) / (345 / 100) * 100 = Monitored session consumed 19.41% of the user mode CPU time on the server
  • (68 / 100) = Session of interest consumed 0.68 seconds of CPU time in the 61.33 second time period
  • (2 / 100) = 0.02 seconds session spent parsing the SQL statement
  • (1 / 100) = 0.01 seconds session spent performing recursive calls to optimize the SQL statement
  • (24,296 / 24,985) * 100 = 97.24% of the consistent gets were performed by fastpath (the statistic definition is apparently not documented – I suspect that it might mean that the blocks were read by direct path reads, thus bypassing the buffer cache – but I suppose that it might mean instead that multiple single-block read requests were combined into a single parallel read request)

The DB CPU statistic in the V$SESS_TIME_MODEL view and the various statistics in the V$OSSTAT view are updated in near real-time – the monitored session only consumed about 0.6 seconds of CPU time for every 60 seconds of execution time.  You will notice that for both Oracle Database 11.2.0.1 and 11.1.0.6 the delta values for the CPU used when call started statistic and the CPU used by this session statistic appear as something other than the number 0 throughout the execution time, so the statistics must be updated at least once a minute in this test run, but that appears to contradict the results shown in Table 8-1 on page 201 of the “Expert Oracle Practices” book where those statistics were only updated 5 minutes and 35 seconds after a SQL statement was submitted (in the book, the CPU used by this session statistic was updated to show only the parse CPU time, until 5 minutes and 35 seconds elapsed).  Is the book wrong, or are the above statistic deltas wrong, or maybe there is another explanation?

Fortunately, while the SQL statement executed, I also captured several statistic delta values from V$SQL for the SQL statement using my Toy Project for Performance Tuning, but a script like that found on page 216 of the “Expert Oracle Practices” book will also collect similar statistics.  The captured deltas for the SQL statement on Oracle 11.2.0.1 are as follows (captured roughly every 60 seconds):

CPU Time  Elapsed Time  Parse Calls  Executions  Fetches  Users Opening  Users Executing  Invalidations  Loads  Disk Reads  Buffer Gets
    0.47         56.84            1           1       13              1                1              0      1      12,148       12,840
    0.50         63.62            0           0       15              0                1              0      0      13,648       14,251
    0.52         64.14            0           0       14              0                1              0      0      13,801       14,514
    0.54         61.81            0           0       15              0                1              0      0      13,922       14,572
    0.45         61.15            0           0       11              0                1              0      0      10,598       11,060
    0.44         69.25            0           0       12              0                1              0      0      11,559       12,036
    0.47         64.16            0           0       14              0                1              0      0      13,318       14,041
    0.48         62.28            0           0       14              0                1              0      0      13,439       14,071
    0.47         64.97            0           0       14              0                1              0      0      13,823       14,386
    0.20         26.24            0           0        7              0                0              0      0       5,730        6,023

There were roughly 13 fetches in the first minute, roughly 15 fetches in the second minute, 14 fetches in the third minute, etc.  The statistics in V$SQL are updated at least once every 6 seconds, so the displayed CPU time values (shown in seconds) are reasonably close to actual CPU consumption times.  You might recognize that the above CPU Time delta values are very close to the delta values shown for the CPU used by this session statistic, so does that mean that the CPU used by this session statistic is updated every 6 seconds or less?  That brings us back to the question, what is considered by the documentation as a “user call” in regard to these two statistics?  Given the above evidence, a “user call” in this context actually includes fetch calls.

Because of the inconsistency with which the CPU used by this session statistic is updated (it might not be updated for more than an hour while executing certain SQL statements), it is a better idea to use the DB CPU statistic found in the V$SESS_TIME_MODEL view (available starting with the Oracle 10.1 release) when trying to determine how much CPU time a particular session is consuming.  Of course operating system tools such as ps and top or my VBS script for Windows may also be used to determine which sessions are consuming CPU time.  The V$SESSION and V$SESSION_WAIT views are also able to help you determine which sessions are currently consuming CPU time and roughly how much CPU time has been consumed since the last wait event ended.

But a parallel question remains, why is a particular session consuming CPU time (the above test case is not necessarily the best example for showing uncontrolled CPU usage, try this test case with the OPTIMIZER_FEATURES_ENABLE parameter set to 10.2.0.4 or lower at the session level)?  The  V$SESSION_LONGOPS and V$SQL_MONITOR (introduced in Oracle 11.1, requires a Tuning Pack license to access) views might provide enough information to determine why a session is consuming CPU time.  A 10046 extended SQL trace could also potentially show why a session is consuming an excessive amount of CPU time, unless, of course, nothing is written to the trace files because the session is performing a CPU intensive operation completely in memory.  What then?  Multiple ORADEBUG SHORT_STACK traces (there is a small chance that creating one of these dumps will crash the session) for the session with the help of Metalink Doc ID 175982.1 could provide a clue of what is happening in the session.  If that does not help find the cause of the CPU usage, you could just declare that the Oracle Wait Interface is Useless (Sometimes) and move along to something more productive (I suggest reviewing that blog series).

Added March 7, 2010:
I thought that the laptop was running a bit sluggish today.  It has been in and out of hibernation on a daily basis for the last two weeks.  I thought that I would check the CPU speed just for fun – this is what I received on 2 checks of the performance with the Power Plan set to High Performance and with the laptop plugged into the electrical power:

I guess that explains why this darn laptop feels so slow – as I write this update to the blog article I see that the core frequency has again dropped:

Is Intel trying to strong arm me into buying one of those Core i7 920QX laptops, or is Microsoft trying to get me to upgrade to Windows 7 on this laptop?

—————-

Update August 10, 2010:

The CPU speed has dipped to 0.210GHz several times, possibly caused by overheating:

——

I think that I finally have a workable solution:





Transitive Closure Causing an Execution Plan Short-Circuit

20 02 2010

February 20, 2010

A recent thread on OTN asked the following question:

Sometimes predicates can be generated due to Transitive Closure, but is it possible to see below mentioned behaviour.  Is it possible to create test case for observing this behaviour?

You can even have cases like this one: if n1 > 10 and n1 < 0, then 0 > 10, which is always false, and therefore can short-circuit an entire branch of an execution plan.

In the OTN thread, Jonathan Lewis directly answered the question posted by the original poster, and I provided an answer to a similar question that involved two columns in a test table.  The setup for the test case included the following SQL statements:

CREATE TABLE T1 AS
SELECT
  ROWNUM C1,
  ROWNUM C2
FROM
  DUAL
CONNECT BY
  LEVEL<=100000;

COMMIT;

EXEC DBMS_STATS.GATHER_TABLE_STATS(OWNNAME=>USER,TABNAME=>'T1')

ALTER SYSTEM FLUSH BUFFER_CACHE;
ALTER SYSTEM FLUSH BUFFER_CACHE;

(Note that submitting the test case using my VBS tool makes short work of temporarily changing the STATISTICS_LEVEL and enabling a 10046 trace while generating a DBMS_XPLAN for a SQL statement: Automated DBMS_XPLAN, Trace, and Send to Excel )

The SQL to generate the test case follows:

ALTER SESSION SET STATISTICS_LEVEL='ALL';
ALTER SESSION SET TRACEFILE_IDENTIFIER = 'SQL_SHORT_CIRCUIT';
ALTER SESSION SET EVENTS '10046 TRACE NAME CONTEXT FOREVER, LEVEL 8';

SELECT
  *
FROM
  T1
WHERE
  C1<=100
  AND C2>=10000
  AND C1>C2;

SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));

SQL_ID  3uk9dajd5cn74, child number 0
-------------------------------------
SELECT T1.* FROM T1 WHERE     C1<=100    AND C2>=10000    AND C1>C2

Plan hash value: 3332582666

---------------------------------------------------------------------------
| Id  | Operation          | Name | Starts | E-Rows | A-Rows |   A-Time   |
---------------------------------------------------------------------------
|*  1 |  FILTER            |      |      1 |        |      0 |00:00:00.01 |
|*  2 |   TABLE ACCESS FULL| T1   |      0 |      1 |      0 |00:00:00.01 |
---------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter(NULL IS NOT NULL)
   2 - filter(("C1">"C2" AND "C2"<100 AND "C1"<=100 AND "C1">10000 AND
              "C2">=10000))

ALTER SESSION SET EVENTS '10046 TRACE NAME CONTEXT OFF';

Notice in the execution plan that the Starts column for the TABLE ACCESS FULL operation is 0 – that line in the execution plan was never executed.  By reviewing the 10046 trace file, you could further confirm that there were no physical reads when the SQL statement executed, which confirms that the full table scan operation was never performed:

PARSING IN CURSOR #2 len=68 dep=0 uid=31 oct=3 lid=31 tim=3008717127 hv=1515606244 ad='a775f1c8'
SELECT T1.* FROM T1 WHERE 
  C1<=100
  AND C2>=10000
  AND C1>C2
END OF STMT
PARSE #2:c=0,e=2320,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=3008717120

EXEC #2:c=0,e=123,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=3008717834
WAIT #2: nam='SQL*Net message to client' ela= 5 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=3008717930
FETCH #2:c=0,e=11,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=3008718038
WAIT #2: nam='SQL*Net message from client' ela= 1777 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=3008719953
STAT #2 id=1 cnt=0 pid=0 pos=1 obj=0 op='FILTER  (cr=0 pr=0 pw=0 time=5 us)'
STAT #2 id=2 cnt=0 pid=1 pos=1 obj=114196 op='TABLE ACCESS FULL T1 (cr=0 pr=0 pw=0 time=0 us)'




What is the Meaning of the %CPU Column in an Explain Plan?

19 02 2010

February 19, 2010

(Forward to the Next Post in the Series)

A question recently appeared on the OTN forums asking what %CPU means in an explain plan output.  I did not see a clear definition of that column in the documentation, so I set up a test case.  We will use the test table from this blog article.  Let’s try creating an explain plan on Oracle 11.2.0.1 for a query:

EXPLAIN PLAN FOR
SELECT
  T1.C1,
  T1.C2,
  T1.C3
FROM
  T1,
  (SELECT
    C1,
    C2
  FROM
    T1
  WHERE
    MOD(C1,3)=0) V
WHERE
  T1.C1=V.C1(+)
  AND V.C1 IS NULL
ORDER BY
  T1.C1 DESC;

The above command wrote a couple of rows into the PLAN_TABLE table.  At this point, we should probably consult the documentation to understand the columns in the PLAN_TABLE table.

COST: Cost of the operation as estimated by the optimizer’s query approach. Cost is not determined for table access operations. The value of this column does not have any particular unit of measurement; it is merely a weighted value used to compare costs of execution plans. The value of this column is a function of the CPU_COST and IO_COST columns.

IO_COST: I/O cost of the operation as estimated by the query optimizer’s approach. The value of this column is proportional to the number of data blocks read by the operation. For statements that use the rule-based approach, this column is null.

CPU_COST: CPU cost of the operation as estimated by the query optimizer’s approach. The value of this column is proportional to the number of machine cycles required for the operation. For statements that use the rule-based approach, this column is null.

We found a couple of interesting columns in the PLAN_TABLE table, so let’s query the table

SELECT
  ID,
  COST,
  IO_COST,
  CPU_COST
FROM
  PLAN_TABLE;

 ID  COST  IO_COST   CPU_COST
--- ----- -------- ----------
  0  1482     1467  364928495
  1  1482     1467  364928495
  2   898      887  257272866
  3   889      887   42272866
  4     0        0       2150

Now let’s display the execution plan:

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY);

Plan hash value: 1923834833

--------------------------------------------------------------------------------------------
| Id  | Operation           | Name         | Rows  | Bytes |TempSpc| Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT    |              | 99000 |  1836K|       |  1482   (2)| 00:00:18 |
|   1 |  SORT ORDER BY      |              | 99000 |  1836K|  2736K|  1482   (2)| 00:00:18 |
|   2 |   NESTED LOOPS ANTI |              | 99000 |  1836K|       |   898   (2)| 00:00:11 |
|   3 |    TABLE ACCESS FULL| T1           |   100K|  1367K|       |   889   (1)| 00:00:11 |
|*  4 |    INDEX UNIQUE SCAN| SYS_C0018049 |    10 |    50 |       |     0   (0)| 00:00:01 |
--------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   4 - access("T1"."C1"="C1")
       filter(MOD("C1",3)=0)

The %CPU is 2 for ID 0, 1, and 2, and the %CPU is 1 for ID 3.  Let’s return to the query of the PLAN_TABLE table and perform a couple of calculations:

SELECT
  ID,
  COST,
  IO_COST,
  COST-IO_COST DIFF,
  CEIL(DECODE(COST,0,0,(COST-IO_COST)/COST)*100) PER_CPU,
  CPU_COST
FROM
  PLAN_TABLE;

 ID  COST  IO_COST  DIFF  PER_CPU   CPU_COST
--- ----- -------- ----- -------- ----------
  0  1482     1467    15        2  364928495
  1  1482     1467    15        2  364928495
  2   898      887    11        2  257272866
  3   889      887     2        1   42272866
  4     0        0     0        0       2150

In the above, I subtracted the IO_COST column from the COST column to derive the DIFF column.  I then divided the value in the DIFF column by the COST column, multiplied the result by 100 to convert the number to a percent, and then rounded up the result to derive the PER_CPU column.  The PER_CPU column seems to match the %CPU column in the DBMS_XPLAN output.  Let’s try another SQL statement:

DELETE FROM PLAN_TABLE;

EXPLAIN PLAN FOR
SELECT
  C1
FROM
  T1
WHERE
  'A'||C1 LIKE 'A%';

Now let’s run the query against the PLAN_TABLE table to see if we are able to predict the values that will appear in the %CPU column of the DBMS_XPLAN output:

SELECT
  ID,
  COST,
  IO_COST,
  COST-IO_COST DIFF,
  CEIL(DECODE(COST,0,0,(COST-IO_COST)/COST)*100) PER_CPU,
  CPU_COST
FROM
  PLAN_TABLE;

 ID  COST  IO_COST  DIFF  PER_CPU   CPU_COST
--- ----- -------- ----- -------- ----------
  0    54       52     2        4   43331709
  1    54       52     2        4   43331709

The above indicates that the %CPU column should show the number 4 on both rows of the execution plan.

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY);

Plan hash value: 2950179127

-------------------------------------------------------------------------------------
| Id  | Operation            | Name         | Rows  | Bytes | Cost (%CPU)|  Time    |
-------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT     |              |  5000 | 25000 |    54   (4)| 00:00:01 |
|*  1 |  INDEX FAST FULL SCAN| SYS_C0018049 |  5000 | 25000 |    54   (4)| 00:00:01 |
-------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter('A'||TO_CHAR("C1") LIKE 'A%')

One of my previous blog articles showed the following execution plan – this was the actual plan displayed by DBMS_XPLAN.DISPLAY_CURSOR after the SQL statement executed:

--------------------------------------------------------------------------------------------------------------
| Id  | Operation            | Name     | Rows  | Bytes | Cost (%CPU)| Time     |    TQ  |IN-OUT| PQ Distrib |
--------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT     |          |       |       |   247 (100)|          |        |      |            |
|   1 |  PX COORDINATOR      |          |       |       |            |          |        |      |            |
|   2 |   PX SEND QC (RANDOM)| :TQ10000 | 10000 |  2236K|   247   (1)| 00:00:03 |  Q1,00 | P->S | QC (RAND)  |
|   3 |    PX BLOCK ITERATOR |          | 10000 |  2236K|   247   (1)| 00:00:03 |  Q1,00 | PCWC |            |
|*  4 |     TABLE ACCESS FULL| T1       | 10000 |  2236K|   247   (1)| 00:00:03 |  Q1,00 | PCWP |            |
--------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   4 - access(:Z>=:Z AND :Z<=:Z)
       filter(("C1"<=10000 AND "C1">=1)) 

Is there anything strange about the %CPU column in the above plan?

Incidentally, a query of SYS.AUX_STATS$ shows the following output (values are used to determine the impact of the CPU_COST column that is displayed in the PLAN_TABLE table):

SELECT
  PNAME,
  PVAL1
FROM
  SYS.AUX_STATS$
WHERE
  PNAME IN ('CPUSPEED','CPUSPEEDNW');

PNAME           PVAL1
---------- ----------
CPUSPEEDNW   2031.271
CPUSPEED 




Michigan OakTable Symposium (Advert)

18 02 2010

February 18, 2010 (Updated April 5, 2010)

Looking for an Oracle training session in the rust belt of the United States?

The Michigan members of the OakTable Network are organizing a two day Oracle training event on the Thursday and Friday (September 16th and 17th, 2010) just before Oracle OpenWorld. OakTable Network members from around the world will be providing sessions at the training event in Ann Arbor, Michigan (not far from the University of Michigan) at the Four Points by Sheraton hotel. Presented sessions will appeal to both DBAs and developers. Seating at the event will be limited to 300 people.

Confirmed Speaker List (See the Official Site for the Latest List):

Alex Gorbachev
Alex Gorbachev is a respected figure in the Oracle world, and a sought-after leader and speaker at Oracle conferences around the globe. He has been recognized as an Oracle ACE Director for his contributions to the community and unmatched set of skills. He is the founder of the Battle Against Any Guess movement promoting scientific troubleshooting techniques. He is currently the Chief Technology Officer at The Pythian Group. Alex has worked for The Pythian Group in several roles. He began by leading a team of database experts in Ottawa. He then moved to Australia to build the company’s presence in the East Asia Pacific region. Now he is back in Ottawa as The Pythian Group’s Chief Technology Officer. In all his work, Alex continues to work towards bridging the gap between business and technology. The search for the perfect fit between technology, engineering talents, and business process is what keeps him up at night. Alex co-authored the book “Expert Oracle Practices: Oracle Database Administration from the Oak Table”.

Andy Zitelli
Andrew Zitelli has thirty years of experience as a software developer, data architect and performance analyst. He has served as a consultant to the aerospace, semiconductor, steel, and pharmaceutical industries. Andrew is proficient working with a broad range of operating systems and languages and has 25 years experience working with ten different relational database products, including 17 years working with Oracle. He holds MS and BA degrees in Computer Science. During the past 30 years, Andrew has taught college-level courses and made presentations at technical conferences and other venues on a wide range of topics. He made presentations at the Hotsos Symposiums in 2007, 2008 and 2009.

Cary Millsap
Cary Millsap is the founder and president of Method R Corporation. He is widely known in the Oracle community as a speaker, educator, consultant and writer. He is the author (with Jeff Holt) of Optimizing Oracle Performance (O’Reilly 2003). Cary is also co-author of Oracle Insights: Tales of the Oak Table. Cary is one of the former founding partners of Hotsos and worked at Oracle for ten years. In the early 1990s, Cary created Oracle’s OFA Standard, which became the default configuration standard for Oracle software installations worldwide. Cary is also a woodworker who builds and repairs furniture in his own shop.

Charles Hooper
Charles Hooper is the IT Manager and an Oracle database administrator at K&M Machine-Fabricating, Inc., where he has been employed since 2000. His role in the company extends well beyond Oracle database administration responsibilities, providing opportunities for database performance tuning, network administration, programming, hardware/software troubleshooting, mentoring fellow IT staff, and end-user training for the Infor Visual Enterprise ERP system as well as other custom developed applications. Charles is well known among the user community of Infor Visual Enterprise due to his years of participation in various user forums answering technical questions, providing the only Oracle presentation at Infor’s 2008 user’s conference, and providing presentations to regional user groups. Prior to joining K&M, he was a computer/technology instructor and Novell Netware administrator. Charles co-authored the book “Expert Oracle Practices: Oracle Database Administration from the Oak Table”.

Dan Fink
Daniel Fink is a senior Oracle database engineer and consultant, specializing in Oracle optimization, troubleshooting, internals, and data recovery. He started as a DBA on Oracle 7.0.16 running Parallel Server on OpenVMS and has experience on major Unix platforms and releases up to 10g. He maintains a library of his research at www.optimaldba.com.

Doug Burns
Doug Burns is an independent contractor who has 20 years of experience working with Oracle in a range of industries and applications. As well as presenting at a number of conferences, he has developed, taught, and edited performance-related courses for both Oracle UK and Learning Tree International.

Jeff Needham
Jeff Needham currently works for Red Hat Software and is responsible for Oracle RDBMS, and GFS/RAC certifications. This includes tending the relationship between RHEL Engineering, Oracle Linux Engineering and Server Technologies. Having founded Scale Abilities with James Morle in 1989, Jeff pioneered high performance NFS for Oracle at Yahoo! using Netapp and AMD technologies. Jeff worked on performance and scalability for Oracle 7 and Oracle 8 during his tenure in the Redwood Shores kernel group. When not at work, he attempts fatherhood, collects Opteron servers and tries to maintain a vintage electronic music studio.

Jeremiah Wilton
Jeremiah Wilton has worked with Oracle technology since 1994. His main claim to fame is having been Amazon.com’s first database administrator, back in the pre-IPO days. For seven years, he helped Amazon.com survive exponential scaling, and a wide variety of nearly-catastrophic technology failures. Jeremiah owned and ran ORA-600 Consulting for a number of years, until it was acquired by Blue Gecko, Inc., a global provider of remote administration for Oracle, MySQL, and E-Business Suite. Jeremiah also teaches the Oracle certificate program for the University of Washington. Jeremiah is an Oracle Certified Master, and a frequent presenter at industry conferences and user groups. His publications and whitepapers can be found at www.bluegecko.net. Jeremiah co-authored the book “Expert Oracle Practices: Oracle Database Administration from the Oak Table”.

Jonathan Lewis
Jonathan Lewis is a well-known figure in the Oracle world with more than 21 years experience of using the database (and several years on other products). He has published two books, contributed to three others, runs a couple of websites and contributes fairly regularly to newsgroups, forums, User Group magazines, and speaking events around the world. Jonathan has been self-employed for most of his time in the IT industry. He specialises in short-term assignments, typically of a design, review, or trouble-shooting  nature.

Joze Senegacnik
Jože Senegačnik has more than 20 years of experience in working with Oracle products. He began in 1988 with Oracle Database version 4 while working for the City of Ljubljana, where he had charge over the city’s municipal and geographic information systems. From 1993 to 2003, he worked in developing GIS systems for the Surveying and Mapping Authority of the Republic of Slovenia, and in the development of applications for other governmental institutions, all based on the Oracle database. More recently, he has specialized in performance optimization, having developed his own toolset for monitoring performance and analyzing trace files. Jože is an internationally recognized speaker. He is a regular speaker at user-group conferences, especially those put on by the Slovenian Oracle Users Group (SIOUG), the Independent Oracle Users Group (IOUG), and the United Kingdom Oracle Users Group (UKOUG). He also speaks routinely at the Hotsos Symposium and Oracle Open World. In addition to sharing his knowledge through conference talks, Jože conducts technical seminars organized either by Oracle University or himself. He was awarded Oracle ACE membership for his long record of positive contributions to the Oracle community. Jože co-authored the book “Expert Oracle Practices: Oracle Database Administration from the Oak Table”.

Mogens Nørgaard
Mogens Nørgaard is technical director at Miracle A/S (http:www.miracleas.dk), a database knowledge center and consulting/training company based in Denmark, and is the cofounder and “father figure” of the OakTable Network. He is a renowned speaker at Oracle conferences all over the world and organizes some highly respected events through Miracle A/S, including the annual MasterClass (2001: Cary Millsap, 2002: Jonathan Lewis, 2003: Steve Adams, 2004: Tom Kyte) and the Miracle Database Forum, which is a 3-day conference for database people. He is also the cofounder of the Danish Oracle User Group (OUGKD) and was voted “Educator of the Year” in Oracle Magazine’s Editor’s Choice Awards, 2003.

Randolf Geist
Randolf Geist has been working with Oracle software for 15 years. Since 2000 he has operated as a freelance database consultant focusing primarily on performance related issues, and in particular helping people to understand and unleash the power of the Oracle cost based optimizer (CBO). He is writing on his blog about CBO-related issues and is also regularly contributing to the official OTN forums. Randolf is a member of the Oracle ACE program and is an Oracle Certified Professional DBA for Oracle Versions 8i, 9i, and 10g. He also maintains SQLTools++, an open-source Oracle GUI for Windows. Randolf co-authored the book “Expert Oracle Practices: Oracle Database Administration from the Oak Table”.

Riyaj Shamsudeen
Riyaj Shamsudeen has 17+ years of experience in Oracle and 16+ years as an Oracle DBA/Oracle Applications DBA. He is the principal DBA for OraInternals, a consulting company resolving many advanced performance, recovery, RAC, and EBS11i issues. Riyaj specializes in RAC and performance issues and has authored many articles, mostly about performance, database internals, optimizer internals, etc. He is a frequent presenter in major conferences such as Hotsos Symposia, UKOUG, RMOUG etc. co-authored the book “Expert Oracle Practices”.

Robyn Sands
Robyn Anderson Sands is a software engineer for Cisco Systems. In a previous incarnation, she worked in Industrial Engineering, Manufacturing Development, and Quality Engineering at Lockheed Martin, supporting the P-7, F-22, and C-130J programs. Robyn has been working with databases and Oracle software since around 1996. She began her work with Oracle by developing tools for scheduling, composite fabrication capacity modeling, and engineering work flow, and progressing to the implementation and administration of data warehouse, PeopleSoft, and SAP systems. Current projects include “architecting” and managing the development of embedded database systems for Cisco customers, and searching for new ways to design and develop database systems with consistent performance and minimal maintenance requirements. She has been a speaker at UKOUG, Miracle conferences, Oracle Open World, and the Hotsos Symposium.  Robyn co-authored the book “Expert Oracle Practices: Oracle Database Administration from the Oak Table”.

Tanel Poder
Tanel Põder is an experienced consultant with deep expertise in Oracle database internals, advanced performance tuning and end-to-end troubleshooting. He specializes in solving complex problems spanning multiple infrastructure layers such as UNIX, Oracle, application servers and storage. He is one of the first Oracle Certified Masters in the world, passing the OCM DBA exam in 2002; and is a frequent speaker at major Oracle conferences worldwide.

Tim Gorman 
Tim Gorman began his IT career in 1984 as a C programmer on UNIX and VMS systems, working on medical and financial systems as an application developer, systems programmer, and systems administrator. He joined Oracle Corporation in 1990 as a consultant, then became an independent consultant in 1998, and has worked for SageLogix since 2000. Gorman is the co-author of Essential Oracle8i Data Warehousing and Oracle8 Data Warehousing. He specializes in performance tuning applications, databases, and systems, as well as data warehouse design and implementation, backup and recovery, architecture and infrastructure, and database administration. Gorman still considers himself a pretty good coder, although the market for C programs has dried up somewhat lately. Tim co-authored the book “Expert Oracle Practices: Oracle Database Administration from the Oak Table”.

———-

Awaiting Confirmation (Subject to Change):

Christian Antognini
Since 1995, Christian Antognini has focused on understanding how the Oracle database engine works. His main interests include logical and physical database design, the integration of databases with Java applications, the query optimizer and basically everything else related to application performance management and optimization. He is currently working as a principal consultant and trainer at Trivadis AG (http://www.trivadis.com) in Zürich, Switzerland. If Christian is not helping one of his customers get the most out of Oracle, he is somewhere lecturing on application performance management or new Oracle database features for developers. In addition to classes and seminars organized by Trivadis, he regularly presents at conferences and user group meetings. He is a proud member of the Trivadis Performance Team and of the OakTable Network. Christian is the author of the book Troubleshooting Oracle Performance (Apress, 2008).

Eric Grancher
Eric Grancher has been working at CERN since 1996 in the Information Technology Division. He has been working on different aspects of databases and application server products: database design consulting, cluster database administration and usage with commodity hardware, application server consulting, database and application server monitoring. He is currently responsible for a team that focuses on database oriented application deployment. He holds an engineer diploma from the French telecommunication engineer school “ENST – Telecom Paris” and a Magistre (Master) of Parallel Computing from “Ecole Normale Suprieure de Lyon”.

James Morle
With 20 years’ experience in professional computing, James Morle has been personally responsible for the architecture and implementation of some of the world’s largest and most complex business systems, including a 3-node Oracle Parallel Server configuration that services 3000 online users. James is a well-respected member of the Oracle community and is the author of the critically acclaimed book Scaling Oracle8i. He is the cofounder of Scale Abilities (http://www.scaleabilities.com), a specialist consulting and training company focusing on aspects of system engineering related to building very large and complex computer systems.  Authored the book “Scaling Oracle8i: Building Highly Scalable OLTP System Architectures”, co-authored the book “Oracle Insights: Tales of the Oak Table”

Marco Gralike
Marco Gralike, working for AMIS Services BV as a Principal Oracle Database Consultant in the Netherlands, has experience as a DBA since 1994 (Oracle 6). Marco is also eager and skillful in other fields, like Operating System Administration and Application Servers, mainly in finding working, performing solutions. Marco has been specializing in Oracle XMLDB, since 2003, focusing on his old love, database administration and performance. He is an Oracle XMLDB enthusiast. He is also a dedicated contributor of the Oracle User Group community, helping people with their steep XMLDB learning curve. To this purpose, Marco also devoted his personal blog site to XMLDB and other Oracle issues. Marco has presented several times in Holland, UKOUG (2007, 2008) and Oracle Open World (2008, 2009). He has been awarded the Oracle ACE title for his work in the Oracle XMLDB area (2007).

———-

The MOTS Executive Committee:

Carol Dacko – OakTable member
Mark Bobak – Oak Table member
Mark Powell – OakTable member
Charles Hooper – OakTable member
Ric Van Dyke – Hotsos Friend
Myke Ratcliff – Esteemed Friend

The Michigan OakTable Symposium (MOTS) is not intended as a money making event. As such, the cost for attending the event has been set as low as possible to essentially “break-even”. The primary mission of the symposium is to provide attendees with logical, structured processes that lead to reproducible success, rather than treating the Oracle Database as a magical, unpredictable, black-box that yields unexpected behavior.

Early registration at a rate of $450 per person will end April 30, 2010. Registration between May 1 and July 31 is $600 per person, and increases to $750 per person after July 31. These prices do not include room hotel costs (roughly $100 per night), but will include a high quality buffet lunch. You may register for the event at the site:

Watch for future updates, agenda, registration details, and more information on the official MOTS site: http://michigan.oaktable.net.

Preliminary Schedule for Thursday, 16 September 2010 and Friday, 17 September 2010: 

Michigan OakTable Schedule

Michigan OakTable Schedule

Abstracts for each of the sessions are located on the official Michigan OakTable site.





Parallel Reasoning

17 02 2010

February 17, 2010 (Updated October 7, 2010: 11.2 documentation links fixed)

This article is a light-weight exploration of parallel query which is available in the Enterprise Edition of Oracle Database.  There are a lot of great articles on the Internet that discuss parallel query benefits and pitfalls, and Metalink contains a couple of decent articles also.  For example, Metalink Doc ID 263153.1 includes the following bit of advice:

“The parallel hint on the object make sure that we access this object in parallel.”

Neat.  Let’s see if it’s true.  We will experiment with the test table found in this blog article, being sure to collect statistics on all of the columns, and executing the test queries on Oracle Database 11.2.0.1 using my VBS tool for automatically generating execution plans.  Here is the query that will be executed:

SELECT /*+ PARALLEL(2) */
  *
FROM
  T1
WHERE
  C1 BETWEEN 1 AND 10000;

The following execution plan was generated for the query:

SQL_ID  gjcx2fjkwt7xc, child number 0
-------------------------------------
SELECT /*+ PARALLEL(2) */    *  FROM    T1  WHERE    C1 BETWEEN 1 AND 
10000

Plan hash value: 2332705540

-----------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name         | Rows  | Bytes | Cost (%CPU)| Time     | Inst   |
-----------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |              |       |       |   343 (100)|          |        |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1           | 10000 |  2236K|   343   (0)| 00:00:05 |  OR112 |
|*  2 |   INDEX RANGE SCAN          | SYS_C0018049 | 10000 |       |    20   (0)| 00:00:01 |  OR112 |
-----------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C1">=1 AND "C1"<=10000)

Note
-----
   - Degree of Parallelism is 1 because of hint

That’s a strange note at the end of the execution plan.  Maybe Doc ID 263153.1 does not apply to Oracle 11.2.0.1, because the query did not execute in parallel?  Let’s try again:

SELECT /*+ PARALLEL(3) */
  *
FROM
  T1
WHERE
  C1 BETWEEN 1 AND 10000;

SQL_ID  45mgp20qp9rfu, child number 0
-------------------------------------
SELECT /*+ PARALLEL(3) */    *  FROM    T1  WHERE    C1 BETWEEN 1 AND 
10000

Plan hash value: 2494645258

--------------------------------------------------------------------------------------------------------------
| Id  | Operation            | Name     | Rows  | Bytes | Cost (%CPU)| Time     |    TQ  |IN-OUT| PQ Distrib |
--------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT     |          |       |       |   329 (100)|          |        |      |            |
|   1 |  PX COORDINATOR      |          |       |       |            |          |        |      |            |
|   2 |   PX SEND QC (RANDOM)| :TQ10000 | 10000 |  2236K|   329   (0)| 00:00:04 |  Q1,00 | P->S | QC (RAND)  |
|   3 |    PX BLOCK ITERATOR |          | 10000 |  2236K|   329   (0)| 00:00:04 |  Q1,00 | PCWC |            |
|*  4 |     TABLE ACCESS FULL| T1       | 10000 |  2236K|   329   (0)| 00:00:04 |  Q1,00 | PCWP |            |
--------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   4 - access(:Z>=:Z AND :Z<=:Z)
       filter(("C1"<=10000 AND "C1">=1))

Note
-----
   - Degree of Parallelism is 3 because of hint

Well, that’s odd.  Doc ID 263153.1 first doesn’t apply to Oracle 11.2.0.1, and then does apply to Oracle 11.2.0.1.  Notice that the calculated total query cost of the first plan is 343 and the calculated total query cost of the second plan is 329.  Time for another test:

SELECT /*+ PARALLEL(4) */
  *
FROM
  T1
WHERE
  C1 BETWEEN 1 AND 10000;

SQL_ID  1m142v1crjs2j, child number 0
-------------------------------------
SELECT /*+ PARALLEL(4) */    *  FROM    T1  WHERE    C1 BETWEEN 1 AND 
10000

Plan hash value: 2494645258

--------------------------------------------------------------------------------------------------------------
| Id  | Operation            | Name     | Rows  | Bytes | Cost (%CPU)| Time     |    TQ  |IN-OUT| PQ Distrib |
--------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT     |          |       |       |   247 (100)|          |        |      |            |
|   1 |  PX COORDINATOR      |          |       |       |            |          |        |      |            |
|   2 |   PX SEND QC (RANDOM)| :TQ10000 | 10000 |  2236K|   247   (1)| 00:00:03 |  Q1,00 | P->S | QC (RAND)  |
|   3 |    PX BLOCK ITERATOR |          | 10000 |  2236K|   247   (1)| 00:00:03 |  Q1,00 | PCWC |            |
|*  4 |     TABLE ACCESS FULL| T1       | 10000 |  2236K|   247   (1)| 00:00:03 |  Q1,00 | PCWP |            |
--------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   4 - access(:Z>=:Z AND :Z<=:Z)
       filter(("C1"<=10000 AND "C1">=1))

Note
-----
   - Degree of Parallelism is 4 because of hint

The calculated total query cost decreased to 247.  OK, if we keep bumping up the parallel degree, the calculated cost becomes lower, so we might as well get it over with and do this:

SQL_ID  9xccz9nu4hrqx, child number 0
-------------------------------------
SELECT /*+ PARALLEL(1000) */    *  FROM    T1  WHERE    C1 BETWEEN 1 
AND 10000

Plan hash value: 2494645258

--------------------------------------------------------------------------------------------------------------
| Id  | Operation            | Name     | Rows  | Bytes | Cost (%CPU)| Time     |    TQ  |IN-OUT| PQ Distrib |
--------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT     |          |       |       |     2 (100)|          |        |      |            |
|   1 |  PX COORDINATOR      |          |       |       |            |          |        |      |            |
|   2 |   PX SEND QC (RANDOM)| :TQ10000 | 10000 |  2236K|     2   (0)| 00:00:01 |  Q1,00 | P->S | QC (RAND)  |
|   3 |    PX BLOCK ITERATOR |          | 10000 |  2236K|     2   (0)| 00:00:01 |  Q1,00 | PCWC |            |
|*  4 |     TABLE ACCESS FULL| T1       | 10000 |  2236K|     2   (0)| 00:00:01 |  Q1,00 | PCWP |            |
--------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   4 - access(:Z>=:Z AND :Z<=:Z)
       filter(("C1"<=10000 AND "C1">=1))

Note
-----
   - Degree of Parallelism is 1000 because of hint

There, we now have a cost of 2 – the query should now finish instantaneously.  🙂  But why didn’t the query excute in parallel when PARALLEL(2) was specified in the hint?  A search of the Internet provides the answer:

Hints on Hinting (page 2)

“The hint parallel(t1, N) does not tell Oracle to run the query in parallel at degree N – it tells the optimizer that when it is calculating the cost of a tablescan on table t1 it should cost for parallel degree N, and if that plan then happens to be the cheapest of all the plans to consider that that’s the plan to use.”

Hints – Again

“But the hint we supplied is only relevant to the tablescan – and we can see it being used in the arithmetic above: the cost_io is the serial I/O cost of the tablescan, the resp_io is the ‘parallel response’ time for the query which is (cost_io / (0.9 * degree)).”

Calculated costs of the access paths matter… so that’s why the first query did not execute in parallel.

For those who decide to rebuild indexes for whatever reason, and decide to do so in parallel, you might be setting yourself up for headaches:

A Gotcha with Parallel Index Builds, Parallel Degree and Query Plans

I haven’t enabled parallelism for my table! How can Oracle go parallel without my consent?  Parallel index (re)build will persistently set the index parallel degree in data dictionary to the value used during build!

Oracle 11.2.0.1 introduced a couple of changes to parallel query, and a couple of those changes are listed below:

http://download.oracle.com/docs/cd/E11882_01/server.112/e17118/sql_elements006.htm#BABHFDDH

“Beginning with Oracle Database 11g Release 2, the PARALLEL and NO_PARALLEL hints are statement-level hints and supersede the earlier object-level hints: PARALLEL_INDEX, NO_PARALLEL_INDEX, and previously specified PARALLEL and NO_PARALLEL hints. For PARALLEL, if you specify integer, then that degree of parallelism will be used for the statement. If you omit integer, then the database computes the degree of parallelism. All the access paths that can use parallelism will use the specified or computed degree of parallelism.”

http://download.oracle.com/docs/cd/E11882_01/server.112/e16541/parallel002.htm

“When the parameter PARALLEL_DEGREE_POLICY is set to AUTO, Oracle Database automatically decides if a statement should execute in parallel or not and what DOP it should use. Oracle Database also determines if the statement can be executed immediately or if it is queued until more system resources are available. Finally, it decides if the statement can take advantage of the aggregated cluster memory or not.

The following example illustrates computing the DOP the statement should use:

SELECT /*+ parallel(auto) */ ename, dname FROM emp e, dept d
WHERE e.deptno=d.deptno;

The following example forces the statement to use Oracle Database 11g, Release 1 (11.1) behavior:

SELECT /*+ parallel(manual) */ ename, dname FROM emp e, dept d WHERE e.deptno=d.deptno;"

Also from the documentation:

“Oracle ignores parallel hints on temporary tables. Refer to CREATE TABLE and Oracle Database Concepts for more information on parallel execution.”

As I mentioned at the beginning of this article, I only intend to provide a light-weight exploration of parallel query, so I will stop here… or better yet after providing a couple of potentially helpful Metalink article references that you can review using your shiny new Apple iPad:

  • Doc ID 263153.1 “FAQ’s about Parallel/Noparallel Hints” (briefly mentioned at the beginning of this article)
  • Doc ID 203238.1 “Using Parallel Execution”
  • Doc ID 826893.1 “Invalid Hint in 10g Can Cause Other Hints To Be Ignored, Including Parallel Hints”
  • Doc ID 199272.1 “Why didn’t my parallel query use the expected number of slaves?”
  • Doc ID 233754.1 “Why doesn’t my query run in parallel?”
  • Doc ID 267330.1 “SQL statements that run in parallel with NO_PARALLEL hints”
  • Doc ID 196938.1 “Why did my query go parallel?”
  • Doc ID 752816.1 “Parallel Update On Table Does Not Work If Statistics Have Been Calculated”
  • Doc ID 237287.1 “How To Verify Parallel Execution is running”
  • Doc ID 457857.1 “Script to monitor parallel queries”
  • Doc ID 280939.1 “Checklist for Performance Problems with Parallel Execution”
  • Doc ID 46234.1 “Interpreting Explain plan”
  • Doc ID 260845.1 “Old and new Syntax for setting Degree of Parallelism”
  • Doc ID 235400.1 “Disable Parallel Execution on Session/System Level”
  • Doc ID 763419.1 “Neither Table DOP nor parallel hint is saved in the Stored Outline hints”
  • Doc ID 6474009.8 “Bug 6474009 – On ASSM tablespaces Scans using Parallel Query can be slower than in 9.2”
  • Doc ID 6748058.8 “Bug 6748058 – A parallel query executes serially due to correlation variable”
  • Doc ID 6402957.8 “Bug 6402957 – Suboptimal parallel query performance for Top-n rank queries.”
  • Doc ID 873392.1 “Ora-04030 with high PGA allocation for ‘kxs-heap-p’ under session heap”
  • Doc ID 844538.1 “Wrong Results For ROWNUM During Parallel Execution on RAC”
  • Doc ID 755975.1 “Parallel Query With Virtual Private Database Returns Wrong Result or Fails With ORA-600[kzrtgpp – kxfxslavesql]”

Be on the lookout for hard hitting parallel query articles by other authors (such as Doug Burns), and try not to abuse this feature.  I will leave you with this paraphrase from the book “Practical Oracle 8i”

Parallel query’s objective is to maximize resource utilization in order to reduce query execution time.  Oracle may select a high CPU consumption plan using a full tablescan, rather than a lower CPU consuming index range scan – this situation may cause performance problems in an OLTP system.  Parallel query is a data crunching, non-scalable, batch processor.





How to Determine which First Rows OPTIMIZER_MODE was Specified

16 02 2010

February 16, 2010

As you are probably aware, recent releases of Oracle (10.1 and above) support several variants of the first rows OPTIMIZER_MODE, in addition to ALL_ROWS, RULE, CHOOSE, and the original FIRST_ROWS (RULE and CHOOSE are now deprecated, and generally FIRST_ROWS should not be used).  When a 10046 trace is generated for a session, the trace file includes a reference (og=) that indicates the optimizer mode in effect for that SQL statement, as described in this article.  Unfortunately, 10046 extended trace files do not make a distinction between the original FIRST_ROWS optimizer mode and the newer variants FIRST_ROWS_1, FIRST_ROWS_10, FIRST_ROWS_100, and FIRST_ROWS_1000 – all will show og=2 in the 10046 trace file.  When the OPTIMIZER_MODE is set to FIRST_ROWS_10, for instance, the optimizer assumes that the client will only read the first 10 rows, and the client will discard the rest of the rows in the result set.  If the optimizer predicts that only eight rows will be returned (or a number less than or equal to 10), the optimizer will likely generate an execution plan similar to what would be generated with the OPTIMIZER_MODE set to ALL_ROWS.  As such, a different execution plan could be generated if the OPTIMIZER_MODE is set to FIRST_ROWS_10 rather than FIRST_ROWS_1000 when the result set is predicted to include, for instance, 120 rows.

Last year a question appeared on the OTN forums asking how to determine which of the FIRST_ROWS optimizer modes was in use based on the contents of a raw 10046 trace file.  Sounds like an interesting request.  If a simultaneous 10053 trace was enabled, or a 10132 trace (as suggested by Jonathan Lewis in the thread), the optimizer mode will be written directly to the same trace file that includes the 10046 trace information, if the SQL statement is hard parsed.  What else can you do?  A trace file generated on Oracle 11.1 and above includes the SQL_ID for the SQL statement in the raw 10046 trace file, while earlier versions include the HASH_VALUE which can be used to determine the SQL_ID.  Unfortunately, there could be multiple child cursors for the same SQL_ID, each potentially using a different value for the OPTIMIZER_MODE.

As a test, we could use a script like the following (using the sample table from this blog article):

ALTER SESSION SET TRACEFILE_IDENTIFIER = 'SQL_OP_MODE_TEST';
ALTER SESSION SET EVENTS '10046 TRACE NAME CONTEXT FOREVER, LEVEL 8';
ALTER SESSION SET OPTIMIZER_MODE='ALL_ROWS';

SELECT
  C1,
  C2,
  C3
FROM
  T1
WHERE
  C1<=50000;

SELECT SYSDATE FROM DUAL;

ALTER SESSION SET OPTIMIZER_MODE='FIRST_ROWS_1';

SELECT
  C1,
  C2,
  C3
FROM
  T1
WHERE
  C1<=50000;

SELECT SYSDATE FROM DUAL;

ALTER SESSION SET OPTIMIZER_MODE='FIRST_ROWS_10';

SELECT
  C1,
  C2,
  C3
FROM
  T1
WHERE
  C1<=50000;

SELECT SYSDATE FROM DUAL;

ALTER SESSION SET OPTIMIZER_MODE='FIRST_ROWS_100';

SELECT
  C1,
  C2,
  C3
FROM
  T1
WHERE
  C1<=50000;

SELECT SYSDATE FROM DUAL;

ALTER SESSION SET OPTIMIZER_MODE='FIRST_ROWS_1000';

SELECT
  C1,
  C2,
  C3
FROM
  T1
WHERE
  C1<=50000;

SELECT SYSDATE FROM DUAL;

ALTER SESSION SET OPTIMIZER_MODE='ALL_ROWS';

ALTER SESSION SET EVENTS '10046 TRACE NAME CONTEXT OFF';

The resulting trace file might contain entries like ths following (when executed on Oracle 10.2.0.4):

PARSING IN CURSOR #1 len=51 dep=0 uid=31 oct=3 lid=31 tim=1934865102 hv=1321303491 ad='94ec5058'
...
PARSE #1:c=0,e=1474,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=1934865097
...
STAT #1 id=1 cnt=50000 pid=0 pos=1 obj=114250 op='TABLE ACCESS FULL T1 (cr=3323 pr=0 pw=0 time=50079 us)'
...
PARSING IN CURSOR #1 len=51 dep=0 uid=31 oct=3 lid=31 tim=1943577683 hv=1321303491 ad='94ec5058'
...
PARSE #1:c=0,e=1694,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=2,tim=1943577677
...
STAT #1 id=1 cnt=50000 pid=0 pos=1 obj=114250 op='TABLE ACCESS BY INDEX ROWID T1 (cr=1803 pr=0 pw=0 time=150071 us)'
STAT #1 id=2 cnt=50000 pid=1 pos=1 obj=114251 op='INDEX RANGE SCAN SYS_C0020571 (cr=143 pr=0 pw=0 time=333 us)'

...
PARSING IN CURSOR #1 len=51 dep=0 uid=31 oct=3 lid=31 tim=1952576477 hv=1321303491 ad='94ec5058'
...
PARSE #1:c=0,e=100,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=2,tim=1952576474
...
STAT #1 id=1 cnt=50000 pid=0 pos=1 obj=114250 op='TABLE ACCESS BY INDEX ROWID T1 (cr=1803 pr=0 pw=0 time=150075 us)'
STAT #1 id=2 cnt=50000 pid=1 pos=1 obj=114251 op='INDEX RANGE SCAN SYS_C0020571 (cr=143 pr=0 pw=0 time=285 us)'
...
PARSING IN CURSOR #1 len=51 dep=0 uid=31 oct=3 lid=31 tim=1961574186 hv=1321303491 ad='94ec5058'
...
PARSE #1:c=0,e=58,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=2,tim=1961574184
...
STAT #1 id=1 cnt=50000 pid=0 pos=1 obj=114250 op='TABLE ACCESS BY INDEX ROWID T1 (cr=1803 pr=0 pw=0 time=150075 us)'
STAT #1 id=2 cnt=50000 pid=1 pos=1 obj=114251 op='INDEX RANGE SCAN SYS_C0020571 (cr=143 pr=0 pw=0 time=298 us)'
...
PARSING IN CURSOR #1 len=51 dep=0 uid=31 oct=3 lid=31 tim=1970536100 hv=1321303491 ad='94ec5058'
...
PARSE #1:c=0,e=28,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=2,tim=1970536097
...
STAT #1 id=1 cnt=50000 pid=0 pos=1 obj=114250 op='TABLE ACCESS BY INDEX ROWID T1 (cr=1803 pr=0 pw=0 time=150075 us)'
STAT #1 id=2 cnt=50000 pid=1 pos=1 obj=114251 op='INDEX RANGE SCAN SYS_C0020571 (cr=143 pr=0 pw=0 time=294 us)'

If you are able to determine the SQL_ID based on the contents of the trace file, you could do something like this:

SELECT
  CHILD_NUMBER CN,
  NAME,
  VALUE,
  ISDEFAULT DEF
FROM
  V$SQL_OPTIMIZER_ENV
WHERE
  SQL_ID='fnk3z1j7c2zf3'
ORDER BY
  CHILD_NUMBER,
  NAME;

 CN NAME                          VALUE           DEF
--- ----------------------------- --------------- ---
  0 active_instance_count         1               YES
  0 bitmap_merge_area_size        1048576         YES
...

Unfortunately, the 10.2.0.4 trace file lacks the SQL_ID, so we need an extra trip into V$SQL:

SELECT
  SE.SQL_ID,
  SE.CHILD_NUMBER CN,
  SE.ADDRESS,
  SE.NAME,
  SE.VALUE,
  SE.ISDEFAULT DEF
FROM
  V$SQL_OPTIMIZER_ENV SE,
  V$SQL S
WHERE
  S.HASH_VALUE=1321303491
  AND S.SQL_ID=SE.SQL_ID
  AND S.CHILD_NUMBER=SE.CHILD_NUMBER
  AND S.ADDRESS=SE.ADDRESS
ORDER BY
  SE.CHILD_NUMBER,
  SE.NAME;

SQL_ID         CN ADDRESS          NAME                          VALUE           DEF
------------- --- ---------------- ----------------------------- --------------- ---
fnk3z1j7c2zf3   0 000007FF94EC5058 active_instance_count         1               YES
fnk3z1j7c2zf3   0 000007FF94EC5058 bitmap_merge_area_size        1048576         YES
fnk3z1j7c2zf3   0 000007FF94EC5058 cpu_count                     4               YES
fnk3z1j7c2zf3   0 000007FF94EC5058 cursor_sharing                exact           YES
fnk3z1j7c2zf3   0 000007FF94EC5058 hash_area_size                131072          NO
fnk3z1j7c2zf3   0 000007FF94EC5058 optimizer_dynamic_sampling    2               YES
fnk3z1j7c2zf3   0 000007FF94EC5058 optimizer_features_enable     10.2.0.4        NO
fnk3z1j7c2zf3   0 000007FF94EC5058 optimizer_index_caching       0               YES
fnk3z1j7c2zf3   0 000007FF94EC5058 optimizer_index_cost_adj      100             YES
fnk3z1j7c2zf3   0 000007FF94EC5058 optimizer_mode                all_rows        YES
fnk3z1j7c2zf3   0 000007FF94EC5058 optimizer_secure_view_merging true            YES
fnk3z1j7c2zf3   0 000007FF94EC5058 parallel_ddl_mode             enabled         YES
fnk3z1j7c2zf3   0 000007FF94EC5058 parallel_dml_mode             disabled        YES
fnk3z1j7c2zf3   0 000007FF94EC5058 parallel_execution_enabled    false           YES
fnk3z1j7c2zf3   0 000007FF94EC5058 parallel_query_mode           enabled         YES
fnk3z1j7c2zf3   0 000007FF94EC5058 parallel_threads_per_cpu      2               YES
fnk3z1j7c2zf3   0 000007FF94EC5058 pga_aggregate_target          204800 KB       YES
fnk3z1j7c2zf3   0 000007FF94EC5058 query_rewrite_enabled         true            YES
fnk3z1j7c2zf3   0 000007FF94EC5058 query_rewrite_integrity       enforced        YES
fnk3z1j7c2zf3   0 000007FF94EC5058 skip_unusable_indexes         true            YES
fnk3z1j7c2zf3   0 000007FF94EC5058 sort_area_retained_size       0               YES
fnk3z1j7c2zf3   0 000007FF94EC5058 sort_area_size                65536           YES
fnk3z1j7c2zf3   0 000007FF94EC5058 sqlstat_enabled               true            NO
fnk3z1j7c2zf3   0 000007FF94EC5058 star_transformation_enabled   false           YES
fnk3z1j7c2zf3   0 000007FF94EC5058 statistics_level              typical         YES
fnk3z1j7c2zf3   0 000007FF94EC5058 workarea_size_policy          auto            YES
fnk3z1j7c2zf3   1 000007FF94EC5058 active_instance_count         1               YES
fnk3z1j7c2zf3   1 000007FF94EC5058 bitmap_merge_area_size        1048576         YES
fnk3z1j7c2zf3   1 000007FF94EC5058 cpu_count                     4               YES
fnk3z1j7c2zf3   1 000007FF94EC5058 cursor_sharing                exact           YES
fnk3z1j7c2zf3   1 000007FF94EC5058 hash_area_size                131072          NO
fnk3z1j7c2zf3   1 000007FF94EC5058 optimizer_dynamic_sampling    2               YES
fnk3z1j7c2zf3   1 000007FF94EC5058 optimizer_features_enable     10.2.0.4        NO
fnk3z1j7c2zf3   1 000007FF94EC5058 optimizer_index_caching       0               YES
fnk3z1j7c2zf3   1 000007FF94EC5058 optimizer_index_cost_adj      100             YES
fnk3z1j7c2zf3   1 000007FF94EC5058 optimizer_mode                first_rows_1    NO
fnk3z1j7c2zf3   1 000007FF94EC5058 optimizer_secure_view_merging true            YES
fnk3z1j7c2zf3   1 000007FF94EC5058 parallel_ddl_mode             enabled         YES
fnk3z1j7c2zf3   1 000007FF94EC5058 parallel_dml_mode             disabled        YES
fnk3z1j7c2zf3   1 000007FF94EC5058 parallel_execution_enabled    false           YES
fnk3z1j7c2zf3   1 000007FF94EC5058 parallel_query_mode           enabled         YES
fnk3z1j7c2zf3   1 000007FF94EC5058 parallel_threads_per_cpu      2               YES
fnk3z1j7c2zf3   1 000007FF94EC5058 pga_aggregate_target          204800 KB       YES
fnk3z1j7c2zf3   1 000007FF94EC5058 query_rewrite_enabled         true            YES
fnk3z1j7c2zf3   1 000007FF94EC5058 query_rewrite_integrity       enforced        YES
fnk3z1j7c2zf3   1 000007FF94EC5058 skip_unusable_indexes         true            YES
fnk3z1j7c2zf3   1 000007FF94EC5058 sort_area_retained_size       0               YES
fnk3z1j7c2zf3   1 000007FF94EC5058 sort_area_size                65536           YES
fnk3z1j7c2zf3   1 000007FF94EC5058 sqlstat_enabled               true            NO
fnk3z1j7c2zf3   1 000007FF94EC5058 star_transformation_enabled   false           YES
fnk3z1j7c2zf3   1 000007FF94EC5058 statistics_level              typical         YES
fnk3z1j7c2zf3   1 000007FF94EC5058 workarea_size_policy          auto            YES

From the above, we see that there were only two child cursors in the library cache for our SQL statement.  Changing the OPTIMIZER_MODE between the various first rows modes did not trigger the generation of a new child cursor (this same behavior is present on Oracle 11.1.0.7 also), so the OPTIMIZER_MODE recorded in V$SQL_OPTIMIZER_ENV is first_rows_1.

A 10046 trace file captured with Oracle 11.1.0.7, executing the SQL statement with just the ALL_ROWS and FIRST_ROWS_1000 OPTIMIZER_MODEs, included the following:

PARSING IN CURSOR #14 len=51 dep=0 uid=60 oct=3 lid=60 tim=5884684690220 hv=1321303491 ad='23b698b8' sqlid='fnk3z1j7c2zf3'
...
PARSE #14:c=31250,e=43048,p=0,cr=140,cu=0,mis=1,r=0,dep=0,og=1,plh=3617692013,tim=5884684690220
...
STAT #14 id=1 cnt=50000 pid=0 pos=1 obj=86190 op='TABLE ACCESS FULL T1 (cr=6497 pr=3268 pw=0 time=0 us cost=890 size=700000 card=50000)'
...
PARSING IN CURSOR #17 len=51 dep=0 uid=60 oct=3 lid=60 tim=5884708721111 hv=1321303491 ad='23b698b8' sqlid='fnk3z1j7c2zf3'
...
PARSE #17:c=15625,e=31248,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=2,plh=4259601085,tim=5884708721111
...
STAT #17 id=1 cnt=50000 pid=0 pos=1 obj=86190 op='TABLE ACCESS BY INDEX ROWID T1 (cr=8260 pr=0 pw=0 time=0 us cost=37 size=14028 card=1002)'
STAT #17 id=2 cnt=50000 pid=1 pos=1 obj=86191 op='INDEX RANGE SCAN SYS_C0015323 (cr=3422 pr=0 pw=0 time=0 us cost=4 size=0 card=0)'

Since the SQL_ID was written to the 10046 trace file, we are able to see the optimizer parameters in effect for the query with the following SQL statement:

SELECT
  CHILD_NUMBER CN,
  NAME,
  VALUE,
  ISDEFAULT DEF
FROM
  V$SQL_OPTIMIZER_ENV
WHERE
  SQL_ID='fnk3z1j7c2zf3'
ORDER BY
  CHILD_NUMBER,
  NAME;

 CN NAME                                  VALUE           DEF
--- ------------------------------------- --------------- ---
  0 _optim_peek_user_binds                false           NO
  0 _optimizer_adaptive_cursor_sharing    false           NO
  0 active_instance_count                 1               YES
  0 bitmap_merge_area_size                1048576         YES
  0 cell_offload_compaction               ADAPTIVE        YES
  0 cell_offload_plan_display             AUTO            YES
  0 cell_offload_processing               true            YES
  0 cpu_count                             2               YES
  0 cursor_sharing                        exact           YES
  0 db_file_multiblock_read_count         32              YES
  0 hash_area_size                        131072          YES
  0 is_recur_flags                        0               YES
  0 optimizer_capture_sql_plan_baselines  false           YES
  0 optimizer_dynamic_sampling            2               YES
  0 optimizer_features_enable             11.1.0.7        YES
  0 optimizer_index_caching               0               YES
  0 optimizer_index_cost_adj              100             YES
  0 optimizer_mode                        all_rows        YES
  0 optimizer_secure_view_merging         true            YES
  0 optimizer_use_invisible_indexes       false           YES
  0 optimizer_use_pending_statistics      false           YES
  0 optimizer_use_sql_plan_baselines      true            YES
  0 parallel_ddl_mode                     enabled         YES
  0 parallel_degree                       0               YES
  0 parallel_dml_mode                     disabled        YES
  0 parallel_execution_enabled            false           YES
  0 parallel_query_default_dop            0               YES
  0 parallel_query_mode                   enabled         YES
  0 parallel_threads_per_cpu              2               YES
  0 pga_aggregate_target                  143360 KB       YES
  0 query_rewrite_enabled                 true            YES
  0 query_rewrite_integrity               enforced        YES
  0 result_cache_mode                     MANUAL          YES
  0 skip_unusable_indexes                 true            YES
  0 sort_area_retained_size               0               YES
  0 sort_area_size                        65536           YES
  0 sqlstat_enabled                       true            NO
  0 star_transformation_enabled           false           YES
  0 statistics_level                      typical         YES
  0 transaction_isolation_level           read_commited   YES
  0 workarea_size_policy                  auto            YES
  1 _optim_peek_user_binds                false           NO
  1 _optimizer_adaptive_cursor_sharing    false           NO
  1 active_instance_count                 1               YES
  1 bitmap_merge_area_size                1048576         YES
  1 cell_offload_compaction               ADAPTIVE        YES
  1 cell_offload_plan_display             AUTO            YES
  1 cell_offload_processing               true            YES
  1 cpu_count                             2               YES
  1 cursor_sharing                        exact           YES
  1 db_file_multiblock_read_count         32              YES
  1 hash_area_size                        131072          YES
  1 is_recur_flags                        0               YES
  1 optimizer_capture_sql_plan_baselines  false           YES
  1 optimizer_dynamic_sampling            2               YES
  1 optimizer_features_enable             11.1.0.7        YES
  1 optimizer_index_caching               0               YES
  1 optimizer_index_cost_adj              100             YES
  1 optimizer_mode                        first_rows_1000 NO
  1 optimizer_secure_view_merging         true            YES
  1 optimizer_use_invisible_indexes       false           YES
  1 optimizer_use_pending_statistics      false           YES
  1 optimizer_use_sql_plan_baselines      true            YES
  1 parallel_ddl_mode                     enabled         YES
  1 parallel_degree                       0               YES
  1 parallel_dml_mode                     disabled        YES
  1 parallel_execution_enabled            false           YES
  1 parallel_query_default_dop            0               YES
  1 parallel_query_mode                   enabled         YES
  1 parallel_threads_per_cpu              2               YES
  1 pga_aggregate_target                  143360 KB       YES
  1 query_rewrite_enabled                 true            YES
  1 query_rewrite_integrity               enforced        YES
  1 result_cache_mode                     MANUAL          YES
  1 skip_unusable_indexes                 true            YES
  1 sort_area_retained_size               0               YES
  1 sort_area_size                        65536           YES
  1 sqlstat_enabled                       true            NO
  1 star_transformation_enabled           false           YES
  1 statistics_level                      typical         YES
  1 transaction_isolation_level           read_commited   YES
  1 workarea_size_policy                  auto            YES

As long as someone did not use more than one of the first rows OPTIMIZER_MODEs, the above query will show the OPTIMIZER_MODE that was in effect at the time of the hard parse.  Of course, if another of the above parameters was also changed when the OPTIMIZER_MODE changed, there is a very good chance that a new child cursor would have been generated.





Plan Cardinality Estimates Problem with 11.1.0.7 and 11.2.0.1

15 02 2010

February 15, 2010

Here is a fun test on Oracle Database 11.1.0.7 and 11.2.0.1 (all posted tests are from 11.2.0.1).

First, we will create a table and collect statistics for the table with indexes on a couple of the columns and histograms on a couple of the columns:

CREATE TABLE T1 (
  C1 NUMBER NOT NULL,
  C2 NUMBER NOT NULL,
  C3 NUMBER NOT NULL,
  C4 NUMBER NOT NULL,
  C5 VARCHAR2(30) NOT NULL,
  C6 VARCHAR2(30) NOT NULL,
  FILLER VARCHAR2(200),
  PRIMARY KEY (C1));

INSERT INTO T1
SELECT
  ROWNUM,
  ROWNUM,
  TRUNC(ROWNUM/100+1),
  TRUNC(ROWNUM/100+1),
  CHR(65+TRUNC(ROWNUM/10000))||TRUNC(ROWNUM/100+1),
  CHR(65+TRUNC(ROWNUM/10000))||TRUNC(ROWNUM/100+1),
  LPAD('A',200,'A')
FROM
  DUAL
CONNECT BY
  LEVEL<=100000;

COMMIT;

CREATE INDEX IND_T1_C3 ON T1(C3);
CREATE INDEX IND_T1_C4 ON T1(C4);
CREATE INDEX IND_T1_C5 ON T1(C5);

EXEC DBMS_STATS.GATHER_TABLE_STATS(OWNNAME=>USER,TABNAME=>'T1',CASCADE=>TRUE,ESTIMATE_PERCENT=>100,METHOD_OPT=>'FOR COLUMNS SIZE 254 C2, C4, C6')

Just for a review of that GATHER_TABLE_STATS procedure, from the documentation:

When gathering statistics on a table, DBMS_STATS gathers information about the data distribution of the columns within the table. The most basic information about the data distribution is the maximum value and minimum value of the column. However, this level of statistics may be insufficient for the optimizer’s needs if the data within the column is skewed. For skewed data distributions, histograms can also be created as part of the column statistics to describe the data distribution of a given column. Histograms are described in more details in “Viewing Histograms“.

Histograms are specified using the METHOD_OPT argument of the DBMS_STATS gathering procedures. Oracle recommends setting the METHOD_OPT to FOR ALL COLUMNS SIZE AUTO. With this setting, Oracle Database automatically determines which columns require histograms and the number of buckets (size) of each histogram. You can also manually specify which columns should have histograms and the size of each histogram.

The table created by the above script will have 100,000 rows with indexes on columns C3, C4, and C5.  Columns C2, C4, and C6 will have histograms with 254 buckets.  Let’s see the maximum values for the table columns (column C2 values are identical to C1, column C4 values are identical to C3, column C6 values are identical to C5)):

SELECT
  MAX(C1) MAX_C1,
  MAX(C3) MAX_C3,
  MAX(C5) MAX_C5
FROM
  T1;

MAX_C1     MAX_C3 MAX_C5
------ ---------- ------
100000       1001 K1001

The maximum value for column C3 is 1001 – most of the distinct values in that column have 100 matching rows, except for the value 1001 which has a single row.  We will try a couple of tests with my VBS tool for automatically generating DBMS_XPLANs, with the DBMS_XPLAN Type set to “ALLSTATS LAST” and Stats Level set to “ALL“.  First, we will try the maximum value for column C3 (and also C4):

SELECT
  *
FROM
  T1
WHERE
  C3=1001;

The returned execution plan is displayed below (after this point the execution plan will be displayed directly below the SQL statement):

SQL_ID  0vcvak7bgbdzt, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C3=1001

Plan hash value: 1220227203

---------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |           |      1 |        |      1 |00:00:00.01 |       3 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1        |      1 |   1000 |      1 |00:00:00.01 |       3 |
|*  2 |   INDEX RANGE SCAN          | IND_T1_C3 |      1 |    400 |      1 |00:00:00.01 |       2 |
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C3"=1001)

OK, it was more or less expected that the cardinality estimate would be incorrect here because there is no histogram on column C3.  It is a bit odd that the optimizer predicts that the index will return 400 rows that then causes 1000 rows to be returned from the table.  Now let’s try the same SQL statement referencing column C4:

SELECT
  *
FROM
  T1
WHERE
  C4=1001;

SQL_ID  d3zfa447tsjrz, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C4=1001

Plan hash value: 7035821

---------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |           |      1 |        |      1 |00:00:00.01 |       3 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1        |      1 |    100 |      1 |00:00:00.01 |       3 |
|*  2 |   INDEX RANGE SCAN          | IND_T1_C4 |      1 |    100 |      1 |00:00:00.01 |       2 |
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C4"=1001)

100 is closer to the actual number of rows than were predicted for the same SQL statement using column C3, so the histogram probably helped.  What happens when we specify values for C3 and C4 that exceed the maximum values in those columns?

SELECT
  *
FROM
  T1
WHERE
  C3=1101;

SQL_ID  7hy399svng33n, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C3=1101

Plan hash value: 1220227203

---------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |           |      1 |        |      0 |00:00:00.01 |       2 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1        |      1 |   1000 |      0 |00:00:00.01 |       2 |
|*  2 |   INDEX RANGE SCAN          | IND_T1_C3 |      1 |    400 |      0 |00:00:00.01 |       2 |
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C3"=1101)

-

SELECT
  *
FROM
  T1
WHERE
  C4=1101;

SQL_ID  at676unwj7uk1, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C4=1101

Plan hash value: 7035821

---------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |           |      1 |        |      0 |00:00:00.01 |       2 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1        |      1 |     90 |      0 |00:00:00.01 |       2 |
|*  2 |   INDEX RANGE SCAN          | IND_T1_C4 |      1 |     90 |      0 |00:00:00.01 |       2 |
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C4"=1101)

In the above, the SQL statement that accesses column C3 continued to estimate the same number of rows would be returned when the value exceeded the maximum value for the column by roughly 10%.  When the same restriction was applied to column C4, the optimizer predicted that 10% less rows would be returned.  Interesting…

SELECT
  *
FROM
  T1
WHERE
  C3=1201;

SQL_ID  f94b21zwvsn11, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C3=1201

Plan hash value: 1220227203

---------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |           |      1 |        |      0 |00:00:00.01 |       2 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1        |      1 |   1000 |      0 |00:00:00.01 |       2 |
|*  2 |   INDEX RANGE SCAN          | IND_T1_C3 |      1 |    400 |      0 |00:00:00.01 |       2 |
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C3"=1201)

-

SELECT
  *
FROM
  T1
WHERE
  C4=1201;

SQL_ID  4sf3hjx44u1sn, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C4=1201

Plan hash value: 7035821

---------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |           |      1 |        |      0 |00:00:00.01 |       2 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1        |      1 |     80 |      0 |00:00:00.01 |       2 |
|*  2 |   INDEX RANGE SCAN          | IND_T1_C4 |      1 |     80 |      0 |00:00:00.01 |       2 |
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C4"=1201)

Exceeding the maximum value by 20% returned the same cardinality estimate for the SQL statement using column C3 as seen earlier, while the cardinality estimate decreased by 20% for the SQL statement accessing column C4.

SELECT
  *
FROM
  T1
WHERE
  C3=1901;

SQL_ID  86z7nbb5u2p26, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C3=1901

Plan hash value: 1220227203

---------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |           |      1 |        |      0 |00:00:00.01 |       2 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1        |      1 |   1000 |      0 |00:00:00.01 |       2 |
|*  2 |   INDEX RANGE SCAN          | IND_T1_C3 |      1 |    400 |      0 |00:00:00.01 |       2 |
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C3"=1901)

-

SELECT
  *
FROM
  T1
WHERE
  C4=1901;

SQL_ID  08rg4uf562h4x, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C4=1901

Plan hash value: 7035821

---------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |           |      1 |        |      0 |00:00:00.01 |       2 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1        |      1 |     10 |      0 |00:00:00.01 |       2 |
|*  2 |   INDEX RANGE SCAN          | IND_T1_C4 |      1 |     10 |      0 |00:00:00.01 |       2 |
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C4"=1901)

When exceeding the maximum value by 90% we see the same pattern, the cardinality estimates for the first SQL statement were unaffected, while the cardinality estimate for the second SQL statement decreased by 90%.  With a value of 2001 specified for column C4 the optimizer’s predicted cardinality decreased to 1 row.

What about value ranges?

SELECT
  *
FROM
  T1
WHERE
  C3 BETWEEN 1101 AND 1201;

SQL_ID  95zzq8vb523gf, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C3 BETWEEN 1101 AND 1201

Plan hash value: 1220227203

---------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |           |      1 |        |      0 |00:00:00.01 |       2 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1        |      1 |    250 |      0 |00:00:00.01 |       2 |
|*  2 |   INDEX RANGE SCAN          | IND_T1_C3 |      1 |    450 |      0 |00:00:00.01 |       2 |
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C3">=1101 AND "C3"<=1201)

Notice that the optimizer is estimating that 250 rows will be returned, which is less than the sum of the estimated 1,000 rows that would be returned for the value 1101 and the estimated 1,000 rows for value 1201.  Let’s try again specifying column C4:

SELECT
  *
FROM
  T1
WHERE
  C4 BETWEEN 1101 AND 1201;

SQL_ID  9t2fv8dcz7jsv, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C4 BETWEEN 1101 AND 1201

Plan hash value: 7035821

---------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |           |      1 |        |      0 |00:00:00.01 |       2 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1        |      1 |    100 |      0 |00:00:00.01 |       2 |
|*  2 |   INDEX RANGE SCAN          | IND_T1_C4 |      1 |     90 |      0 |00:00:00.01 |       2 |
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C4">=1101 AND "C4"<=1201)

Interesting – the index is predicted to return 90 rows which then causes the table to return 100 rows (edit: Oracle 10.2.0.2 predicts 90 rows for both the index and the table).  Let’s try again specifying ranges that exceed the maximum values by 90% to 100%:

SELECT
  *
FROM
  T1
WHERE
  C3 BETWEEN 1901 AND 2001;

SQL_ID  99btm350uvvbp, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C3 BETWEEN 1901 AND 2001

Plan hash value: 1220227203

---------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |           |      1 |        |      0 |00:00:00.01 |       2 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1        |      1 |    250 |      0 |00:00:00.01 |       2 |
|*  2 |   INDEX RANGE SCAN          | IND_T1_C3 |      1 |    450 |      0 |00:00:00.01 |       2 |
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C3">=1901 AND "C3"<=2001)

-

SELECT
  *
FROM
  T1
WHERE
  C4 BETWEEN 1901 AND 2001;

SQL_ID  bnwyf98m74q26, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C4 BETWEEN 1901 AND 2001

Plan hash value: 7035821

---------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |           |      1 |        |      0 |00:00:00.01 |       2 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1        |      1 |    100 |      0 |00:00:00.01 |       2 |
|*  2 |   INDEX RANGE SCAN          | IND_T1_C4 |      1 |     10 |      0 |00:00:00.01 |       2 |
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C4">=1901 AND "C4"<=2001)

The first query is predicting the same number of rows will be returned as seen earlier.  The second query is again predicting that 100 rows will be returned from the table as a result of the 10 predicted rows that will be returned from the index (edit: Oracle 10.2.0.2 predicts 10 rows for both the index and the table).  When the range was changed to 1101 through 2001, the same cardinality estimates displayed for the range of 1101 to 1201 were again returned for both SQL statements.

If the above accurately depicts what happens when the maximum recorded value for a column is exceeded, what might happen when statistics are not gathered on a regular basis?  Hold that thought.

Let’s try again using a value range for C3 and C4 that are not beyond the maximum values for the columns:

SELECT
  *
FROM
  T1
WHERE
  C3 BETWEEN 101 AND 201;

SQL_ID  8jd9h693mbkvc, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C3 BETWEEN 101 AND 201

Plan hash value: 1220227203

---------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |           |      1 |        |  10100 |00:00:00.02 |     547 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1        |      1 |    250 |  10100 |00:00:00.02 |     547 |
|*  2 |   INDEX RANGE SCAN          | IND_T1_C3 |      1 |    450 |  10100 |00:00:00.01 |     124 |
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C3">=101 AND "C3"<=201)

-

SELECT
  *
FROM
  T1
WHERE
  C4 BETWEEN 101 AND 201;

SQL_ID  2bk0njs0atfpw, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C4 BETWEEN 101 AND 201

Plan hash value: 7035821

---------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |           |      1 |        |  10100 |00:00:00.02 |     547 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1        |      1 |  10039 |  10100 |00:00:00.02 |     547 |
|*  2 |   INDEX RANGE SCAN          | IND_T1_C4 |      1 |  10039 |  10100 |00:00:00.01 |     124 |
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C4">=101 AND "C4"<=201)

Once again, the first SQL statement is estimating that the index range scan will return 450 rows which will then cause the table to return 250 rows.  In actuality, both the index and the table return 10,100 rows (do we possibly have a statistics problem here?).  The second query returns cardinality estimates that are closer to the actual number of rows returned – the histogram helped here.

Let’s try again with a wider value range:

SELECT
  *
FROM
  T1
WHERE
  C3 BETWEEN 101 AND 1401;

SQL_ID  0bapwrbn3ch8j, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C3 BETWEEN 101 AND 1401

Plan hash value: 1220227203

---------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |           |      1 |        |  90001 |00:00:00.13 |    4865 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1        |      1 |    250 |  90001 |00:00:00.13 |    4865 |
|*  2 |   INDEX RANGE SCAN          | IND_T1_C3 |      1 |    450 |  90001 |00:00:00.04 |    1090 |
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C3">=101 AND "C3"<=1401)

-

SELECT
  *
FROM
  T1
WHERE
  C4 BETWEEN 101 AND 1401;

SQL_ID  3ppn43z5ukur6, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C4 BETWEEN 101 AND 1401

Plan hash value: 3617692013

------------------------------------------------------------------------------------
| Id  | Operation         | Name | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |      |      1 |        |  90001 |00:00:00.05 |    4147 |
|*  1 |  TABLE ACCESS FULL| T1   |      1 |  89961 |  90001 |00:00:00.05 |    4147 |
------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter(("C4">=101 AND "C4"<=1401))

Again, the cardinality estimates and execution plan are the same as before for the query using column C3, even though we are selecting 90% of the rows in the table.  The query using column C4 switched to a full table scan, and has a much more accurate cardinality estimate.  This same pattern holds true regardless of the values specified for the low and high ends of the range.

Let’s switch back to SQL*Plus and try a couple of experiments with bind variables (note that I am actually submitting the SQL statements using my Toy Project so that I do not have to watch all of the rows scroll on the screen):

VARIABLE N1 NUMBER
VARIABLE N2 NUMBER

ALTER SESSION SET STATISTICS_LEVEL='ALL';

EXEC :N1:=101
EXEC :N2:=1401

SET ARRAYSIZE 100

SELECT
  *
FROM
  T1
WHERE
  C3 BETWEEN :N1 AND :N2;

...

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));

SQL_ID  2ksn64btq6fx4, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C3 BETWEEN :1 AND :2

Plan hash value: 108045900

----------------------------------------------------------------------------------------------------
| Id  | Operation                    | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
----------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |           |      1 |        |  90001 |00:00:00.18 |    4865 |
|*  1 |  FILTER                      |           |      1 |        |  90001 |00:00:00.18 |    4865 |
|   2 |   TABLE ACCESS BY INDEX ROWID| T1        |      1 |    250 |  90001 |00:00:00.13 |    4865 |
|*  3 |    INDEX RANGE SCAN          | IND_T1_C3 |      1 |    450 |  90001 |00:00:00.04 |    1090 |
----------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter(:1<=:2)
   3 - access("C3">=:1 AND "C3"<=:2)

The same execution plan as returned when we used literals (constants), so bind peeking is probably working.  Now let’s try the query that accesses column C4:

SELECT
  *
FROM
  T1
WHERE
  C4 BETWEEN :N1 AND :N2;

...

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));

SQL_ID  gwgk5h8u3k4tp, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C4 BETWEEN :1 AND :2

Plan hash value: 3332582666

-------------------------------------------------------------------------------------
| Id  | Operation          | Name | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
-------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      |      1 |        |  90001 |00:00:00.10 |    4147 |
|*  1 |  FILTER            |      |      1 |        |  90001 |00:00:00.10 |    4147 |
|*  2 |   TABLE ACCESS FULL| T1   |      1 |  89961 |  90001 |00:00:00.05 |    4147 |
-------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter(:1<=:2)
   2 - filter(("C4">=:1 AND "C4"<=:2))

Bind variable peeking was used to obtain a close estimate for the cardinalities.  So, what happens when we change the value of bind variable N2?

EXEC :N2:=101

SELECT
  *
FROM
  T1
WHERE
  C3 BETWEEN :N1 AND :N2;

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));

SQL_ID  2ksn64btq6fx4, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C3 BETWEEN :1 AND :2

Plan hash value: 108045900

----------------------------------------------------------------------------------------------------
| Id  | Operation                    | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
----------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |           |      1 |        |    100 |00:00:00.01 |       7 |
|*  1 |  FILTER                      |           |      1 |        |    100 |00:00:00.01 |       7 |
|   2 |   TABLE ACCESS BY INDEX ROWID| T1        |      1 |    250 |    100 |00:00:00.01 |       7 |
|*  3 |    INDEX RANGE SCAN          | IND_T1_C3 |      1 |    450 |    100 |00:00:00.01 |       3 |
----------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter(:1<=:2)
   3 - access("C3">=:1 AND "C3"<=:2)

-

SELECT
  *
FROM
  T1
WHERE
  C3 BETWEEN :N1 AND :N2;

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));

SQL_ID  gwgk5h8u3k4tp, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C4 BETWEEN :1 AND :2

Plan hash value: 3332582666

-------------------------------------------------------------------------------------
| Id  | Operation          | Name | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
-------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      |      1 |        |    100 |00:00:00.01 |    3263 |
|*  1 |  FILTER            |      |      1 |        |    100 |00:00:00.01 |    3263 |
|*  2 |   TABLE ACCESS FULL| T1   |      1 |  89961 |    100 |00:00:00.01 |    3263 |
-------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - filter(:1<=:2)
   2 - filter(("C4">=:1 AND "C4"<=:2))

The bind variable in the presence of bind peeking with a histogram came back to bit us – ideally Oracle would have used an index range scan for this set of bind variables.

Let’s add another 10,000 rows to the table without gathering statistics and see what happens to the cardinality estimates in the plans:

INSERT INTO T1
SELECT
  (100000+ROWNUM),
  (100000+ROWNUM),
  TRUNC((100000+ROWNUM)/100+1),
  TRUNC((100000+ROWNUM)/100+1),
  CHR(65+TRUNC((100000+ROWNUM)/10000))||TRUNC((100000+ROWNUM)/100+1),
  CHR(65+TRUNC((100000+ROWNUM)/10000))||TRUNC((100000+ROWNUM)/100+1),
  LPAD('A',200,'A')
FROM
  DUAL
CONNECT BY
  LEVEL<=100000;

COMMIT;

ALTER SYSTEM FLUSH SHARED_POOL;

Here are the execution plans:

SELECT
  *
FROM
  T1
WHERE
  C3=1901;

SQL_ID  86z7nbb5u2p26, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C3=1901

Plan hash value: 1220227203

---------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |           |      1 |        |    100 |00:00:00.01 |       8 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1        |      1 |   1000 |    100 |00:00:00.01 |       8 |
|*  2 |   INDEX RANGE SCAN          | IND_T1_C3 |      1 |    400 |    100 |00:00:00.01 |       4 |
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C3"=1901)

-

SELECT
  *
FROM
  T1
WHERE
  C4=1901;

SQL_ID  08rg4uf562h4x, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C4=1901

Plan hash value: 7035821

---------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |           |      1 |        |    100 |00:00:00.01 |       8 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1        |      1 |     10 |    100 |00:00:00.01 |       8 |
|*  2 |   INDEX RANGE SCAN          | IND_T1_C4 |      1 |     10 |    100 |00:00:00.01 |       4 |
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C4"=1901)

The cardinality estimates are unchanged from what we saw earlier.  The first query is estimating 10 times too many rows will be returned, and the second query is estimating 10 times too few rows will be returned.  Let’s delete the rows that were just added and check a couple of statistics:

DELETE FROM
  T1
WHERE
  C1>100000;

100000 rows deleted.

COMMIT;

SELECT
  SUBSTR(COLUMN_NAME,1,3) COL,
  DENSITY,
  NUM_BUCKETS,
  LAST_ANALYZED
FROM
  DBA_TAB_COLUMNS
WHERE
  TABLE_NAME='T1'
ORDER BY
  1;

COL    DENSITY NUM_BUCKETS LAST_ANAL
--- ---------- ----------- ---------
C1
C2      .00001         254 14-FEB-10
C3
C4   .00099998         254 14-FEB-10
C5
C6   .00099998         254 14-FEB-10
FIL

No density values for columns C1, C3, or C5 and the LAST_ANALYZED column is NULL for those same entries (edit: same results on Oracle 10.2.0.2).  Let’s try collecting statistics again without specifying the columns for which histograms should be created:

EXEC DBMS_STATS.GATHER_TABLE_STATS(OWNNAME=>USER,TABNAME=>'T1',CASCADE=>TRUE,ESTIMATE_PERCENT=>100,NO_INVALIDATE=>FALSE)

SELECT
  SUBSTR(COLUMN_NAME,1,3) COL,
  DENSITY,
  NUM_BUCKETS,
  LAST_ANALYZED
FROM
  DBA_TAB_COLUMNS
WHERE
  TABLE_NAME='T1'
ORDER BY
  1;

COL    DENSITY NUM_BUCKETS LAST_ANAL
--- ---------- ----------- ---------
C1      .00001           1 14-FEB-10
C2      .00001           1 14-FEB-10
C3  .000999001           1 14-FEB-10
C4  .000999001           1 14-FEB-10
C5  .000999001           1 14-FEB-10
C6  .000999001           1 14-FEB-10
FIL          1           1 14-FEB-10

Now we have no histograms, but the density and LAST_ANALYZED columns are populated for all rows returned by the above query (edit: same results on Oracle 10.2.0.2).  For fun let’s retry one of the queries that returned odd cardinality estimates earlier:

SELECT
  *
FROM
  T1
WHERE
  C3 BETWEEN 101 AND 201;

SQL_ID  8jd9h693mbkvc, child number 0
-------------------------------------
SELECT    *  FROM    T1  WHERE    C3 BETWEEN 101 AND 201

Plan hash value: 1220227203

---------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |           |      1 |        |  10100 |00:00:00.02 |     547 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1        |      1 |  10200 |  10100 |00:00:00.02 |     547 |
|*  2 |   INDEX RANGE SCAN          | IND_T1_C3 |      1 |  10200 |  10100 |00:00:00.01 |     124 |
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C3">=101 AND "C3"<=201)

The estimated cardinality is just about as accurate as it was with the query that accessed column C4 which had a histogram.

What are your thoughts?  Is the METHOD_OPT parameter of DBMS_STATS.GATHER_TABLE_STATS only used to specify how histograms will be collected for columns, or does that parameter also specify for which columns column-level statistics should be gathered?  If you again collect statistics using the DBMS_STATS.GATHER_TABLE_STATS command found near the start of this article, the query of DBA_TAB_COLUMNS returns the following, which is what was originally expected (edit: same results on Oracle 10.2.0.2):

COL    DENSITY NUM_BUCKETS LAST_ANAL
--- ---------- ----------- ---------
C1      .00001           1 14-FEB-10
C2      .00001         254 14-FEB-10
C3  .000999001           1 14-FEB-10
C4   .00099998         254 14-FEB-10
C5  .000999001           1 14-FEB-10
C6   .00099998         254 14-FEB-10
FIL          1           1 14-FEB-10

——-

Follow-up (8 hours after this article was scheduled to appear):

It is important at times to check more than one source in the Oracle documentation (bold/italic emphasis is mine):

“METHOD_OPT – The value controls column statistics collection and histogram creation.”

Here is an example where Christian Antognini tried to drive that point home:

“Since the syntax is FOR ALL INDEXED COLUMNS, you are gathering statistics for all indexed columns only. I.e. not for all columns. FOR ALL COLUMNS should be used for that…”

“When the option FOR ALL INDEXED COLUMNS is specified, columns statistics are gathered only for the indexed columns.”

“My point was that the parameter method_opt not only impacts histograms, but also column statistics.”

Greg Rahn also made the point in this blog article.

“The METHOD_OPT parameter of DBMS_STATS controls two things:

  1. on which columns statistics will be collected
  2. on which columns histograms will be collected (and how many buckets)”

The message of this blog article is to make certain that you know what the GATHER_TABLE_STATS procedure is actually doing when you use the METHOD_OPT parameter (or alter the default value for the parameter).  The apparent benefit from having the histogram in place might actually be a false benefit – it might be that previously you were not updating the column statistics for that column, until you started creating a histogram on that column (assuming that you were previously collecting histograms on other columns in the table, and you assumed that column statistics were updated for the remaining columns).

Incidentally, if instead of using this to collect statistics for the table:

EXEC DBMS_STATS.GATHER_TABLE_STATS(OWNNAME=>USER,TABNAME=>'T1',CASCADE=>TRUE,ESTIMATE_PERCENT=>100,METHOD_OPT=>'FOR COLUMNS SIZE 254 C2, C4, C6')

You used this:

EXEC DBMS_STATS.GATHER_TABLE_STATS(OWNNAME=>USER,TABNAME=>'T1',CASCADE=>TRUE,ESTIMATE_PERCENT=>100,METHOD_OPT=>'FOR ALL INDEXED COLUMNS size skewonly')

You would end up with the following when executing the query against DBA_TAB_COLUMNS:

COL    DENSITY NUM_BUCKETS LAST_ANAL
--- ---------- ----------- ---------
C1      .00001           1 15-FEB-10
C2
C3  .000999001           1 15-FEB-10
C4  .000999001           1 15-FEB-10
C5   .00099998         254 15-FEB-10
C6
FIL

The above output confirms Christian Antognini’s comment in the OTN thread – column-level statistics were not collected for columns C2, C6, and FILLER.  There is effectively no histogram on columns C3 and C4 (a single bucket, therefore no histogram), but the cardinality estimates in the plan will be close because column-level statistics are present for columns C3 and C4.





V$FILESTAT is Wrong?

13 02 2010

February 13, 2010

While describing file monitoring in chapter 8 of the Expert Oracle Practices book, one of the interesting items that Randolf and I mentioned was an apparent inconsistency in V$FILESTAT, but we then went on to explain why the inconsistency is present.  To see this inconsistency, I will bounce an 11.1.0.7 database, execute a couple of SQL statements to force physical reads (the SQL statements are not important to this experiment), and then check the current values in V$FILESTAT.  The following script will be executed to show the V$FILESTAT statistics and also the statistics from V$FILE_HISTOGRAM:

spool fileactivity.txt
set linesize 160
set pagesize 2000

SELECT
  FILE#,
  PHYRDS,
  PHYWRTS,
  PHYBLKRD,
  PHYBLKWRT,
  SINGLEBLKRDS,
  READTIM,
  WRITETIM,
  SINGLEBLKRDTIM,
  AVGIOTIM,
  LSTIOTIM,
  MINIOTIM,
  MAXIORTM,
  MAXIOWTM
FROM
  V$FILESTAT
WHERE
  FILE# IN (6,7);

SELECT
  FILE#,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,1,SINGLEBLKRDS,0)) MILLI1,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,2,SINGLEBLKRDS,0)) MILLI2,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,4,SINGLEBLKRDS,0)) MILLI4,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,8,SINGLEBLKRDS,0)) MILLI8,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,16,SINGLEBLKRDS,0)) MILLI16,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,32,SINGLEBLKRDS,0)) MILLI32,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,64,SINGLEBLKRDS,0)) MILLI64,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,128,SINGLEBLKRDS,0)) MILLI128,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,256,SINGLEBLKRDS,0)) MILLI256,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,512,SINGLEBLKRDS,0)) MILLI512,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,1024,SINGLEBLKRDS,0)) MILLI1024,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,2048,SINGLEBLKRDS,0)) MILLI2048,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,4096,SINGLEBLKRDS,0)) MILLI4096
FROM
  V$FILE_HISTOGRAM
WHERE
  FILE# IN (6,7)
GROUP BY
  FILE#
ORDER BY
  FILE#;

spool off

So, what is the inconsistency?  Here is the output of the above SQL statements:

FILE# PHYRDS PHYWRTS PHYBLKRD PHYBLKWRT SINGLEBLKRDS READTIM WRITETIM SINGLEBLKRDTIM AVGIOTIM LSTIOTIM MINIOTIM MAXIORTM MAXIOWTM
----- ------ ------- -------- --------- ------------ ------- -------- -------------- -------- -------- -------- -------- --------
    6     13       9       13         9            2      25        0              8        0        0        0        9        0
    7  27983   39608   138431    107305        13693    6073  3702202           1719        0        0        0       36      447 

FILE# MILLI1 MILLI2 MILLI4 MILLI8 MILLI16 MILLI32 MILLI64 MILLI128 MILLI256 MILLI512 MILLI1024 MILLI2048 MILLI4096
----- ------ ------ ------ ------ ------- ------- ------- -------- -------- -------- --------- --------- ---------
    6      0      0      0      0       0       0       2        0        0        0         0         0         0
    7  12816    222     68     79     108     304      80       12        3        1         0         0         0

So, what is the inconsistency?  Let’s ignore file #7 for a moment and take a look at file #6.  In the above output, the SINGLEBLKRDS column indicates that there were 2 single block reads of file #6, and the SINGLEBLKRDTIM column indicates that the two single block reads required 8 centiseconds (0.08 seconds).  The V$FILE_HISTOGRAM output shows that there were two block reads of file #6 that completed in the range of 32ms (0.032 seconds) and 63.99999ms (0.06399999 seconds).  Those two sets of statistics are consistent, so where is the inconsistency?

Let’s check a couple of the statistics from the output of V$FILESTAT and check the definitions from the documentation:

 2 SINGLEBLKRDS - Number of single block reads
13 PHYBLKRD - Number of physical blocks read
13 PHYRDS - Number of physical reads done

Is the inconsistency clear now?  If 2 of the 13 blocks that were read from the tablespace were read by single block reads, that means that 11 of the blocks were read by something other than single block reads.  Single block reads, by definition, read one block during each read request, so 2 of the 13 physical reads were read by single block reads and that means 11 of the read request were something other than single block reads.  That means 11 blocks were read in 11 read calls by something other than single block reads – were they read by multi-block reads?  Think about that for a moment.

Do those columns really mean something other than what the documentation states?  Is this another bug in the V$FILESTAT view?  Bugs?  From Metalink:

  • V$FILESTAT WRITETIM Shows Very High Values [ID 168930.1]
  • Bug 4942939 – Very high values for ODM/ASM readtim/writetim in V$FILESTAT [ID 4942939.8]
  • Bug 2481002 – V$FILESTAT.AVGIOTIM is incorrect [ID 2481002.8]

All of the above bugs were fixed prior to Oracle 11.1.0.7.  Maybe the next step is to look for more information about V$FILESTAT:

OK, now that you are back from reading the above links, how is it possible to read 11 blocks in a total of 11 read requests when none of the 11 reads are single block reads?  Maybe another script will help answer that question:

CONNECT SYS/SYSPASSWORD AS SYSDBA

CREATE OR REPLACE TRIGGER STARTUP_10046_TRACE AFTER STARTUP ON DATABASE
BEGIN
  EXECUTE IMMEDIATE 'ALTER SYSTEM SET MAX_DUMP_FILE_SIZE=UNLIMITED';
  EXECUTE IMMEDIATE 'ALTER SYSTEM SET TIMED_STATISTICS=TRUE';
  EXECUTE IMMEDIATE 'ALTER SYSTEM SET EVENTS ''10046 TRACE NAME CONTEXT FOREVER, LEVEL 12''';
END;
/

SHUTDOWN IMMEDIATE;

STARTUP

spool fileactivitystartup.txt
set linesize 160
set pagesize 2000

SELECT
  FILE#,
  PHYRDS,
  PHYWRTS,
  PHYBLKRD,
  PHYBLKWRT,
  SINGLEBLKRDS,
  READTIM,
  WRITETIM,
  SINGLEBLKRDTIM,
  AVGIOTIM,
  LSTIOTIM,
  MINIOTIM,
  MAXIORTM,
  MAXIOWTM
FROM
  V$FILESTAT
WHERE
  FILE# IN (6,7);

SELECT
  FILE#,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,1,SINGLEBLKRDS,0)) MILLI1,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,2,SINGLEBLKRDS,0)) MILLI2,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,4,SINGLEBLKRDS,0)) MILLI4,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,8,SINGLEBLKRDS,0)) MILLI8,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,16,SINGLEBLKRDS,0)) MILLI16,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,32,SINGLEBLKRDS,0)) MILLI32,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,64,SINGLEBLKRDS,0)) MILLI64,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,128,SINGLEBLKRDS,0)) MILLI128,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,256,SINGLEBLKRDS,0)) MILLI256,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,512,SINGLEBLKRDS,0)) MILLI512,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,1024,SINGLEBLKRDS,0)) MILLI1024,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,2048,SINGLEBLKRDS,0)) MILLI2048,
  MAX(DECODE(SINGLEBLKRDTIM_MILLI,4096,SINGLEBLKRDS,0)) MILLI4096
FROM
  V$FILE_HISTOGRAM
WHERE
  FILE# IN (6,7)
GROUP BY
  FILE#
ORDER BY
  FILE#;

spool off

ALTER SYSTEM SET EVENTS '10046 TRACE NAME CONTEXT FOREVER, LEVEL 12';

DROP TRIGGER STARTUP_10046_TRACE;

The output of the above script follows:

FILE# PHYRDS PHYWRTS PHYBLKRD PHYBLKWRT SINGLEBLKRDS READTIM WRITETIM SINGLEBLKRDTIM AVGIOTIM LSTIOTIM MINIOTIM MAXIORTM MAXIOWTM
----- ------ ------- -------- --------- ------------ ------- -------- -------------- -------- -------- -------- -------- --------
    6      4       1        4         1            1       2        0              2        0        2        0        2        0
    7      4       1        4         1            1       2        0              2        0        2        0        2        0

FILE# MILLI1 MILLI2 MILLI4 MILLI8 MILLI16 MILLI32 MILLI64 MILLI128 MILLI256 MILLI512 MILLI1024 MILLI2048 MILLI4096
----- ------ ------ ------ ------ ------- ------- ------- -------- -------- -------- --------- --------- ---------
    6      0      0      0      0       0       1       0        0        0        0         0         0         0
    7      0      0      0      0       0       1       0        0        0        0         0         0         0

Again we see the inconsistency SINGLEBLKRDS = 1, PHYBLKRD = 4, PHYRDS = 4 – therefore there were 3 blocks read in 3 physical reads that were not single block reads.  How is this possible?  Maybe we should check the trace files?  The trace file for the session performing the STARTUP command contains the following:

...
WAIT #5: nam='direct path read' ela= 17 file number=1 first dba=1 block cnt=1 obj#=369 tim=7842773692
WAIT #5: nam='direct path read' ela= 11153 file number=2 first dba=1 block cnt=1 obj#=369 tim=7842784875
WAIT #5: nam='direct path read' ela= 19974 file number=3 first dba=1 block cnt=1 obj#=369 tim=7842804886
WAIT #5: nam='direct path read' ela= 1 file number=4 first dba=1 block cnt=1 obj#=369 tim=7842804932
WAIT #5: nam='direct path read' ela= 1 file number=5 first dba=1 block cnt=1 obj#=369 tim=7842804959
WAIT #5: nam='direct path read' ela= 1 file number=6 first dba=1 block cnt=1 obj#=369 tim=7842804981
...

The trace file for LGWR contains the following:

...
WAIT #0: nam='direct path read' ela= 5 file number=1 first dba=1 block cnt=1 obj#=-1 tim=7842890656
WAIT #0: nam='direct path read' ela= 1 file number=2 first dba=1 block cnt=1 obj#=-1 tim=7842890694
WAIT #0: nam='direct path read' ela= 1 file number=3 first dba=1 block cnt=1 obj#=-1 tim=7842890726
WAIT #0: nam='direct path read' ela= 1 file number=4 first dba=1 block cnt=1 obj#=-1 tim=7842890756
WAIT #0: nam='direct path read' ela= 0 file number=5 first dba=1 block cnt=1 obj#=-1 tim=7842890801
WAIT #0: nam='direct path read' ela= 1 file number=6 first dba=1 block cnt=1 obj#=-1 tim=7842890832
...

Let’s see: 1 single block read in the SYS session, 1 single block read in the LGWR trace file, therefore 1=2?  That makes complete sense.  What you probably will not find in the documentation is a statement that the SINGLEBLKRDS column of V$FILESTAT and the statistics in V$FILE_HISTOGRAM correspond to the “db file sequential read” wait event, and do not include statistics for single block reads associated with the “direct path read” wait event.  (At least in this case.)

What about Oracle 11.2.0.1?  Here is the output of the two SQL statements after executing a couple of queries following a database bounce:

FILE# PHYRDS PHYWRTS PHYBLKRD PHYBLKWRT SINGLEBLKRDS READTIM WRITETIM SINGLEBLKRDTIM AVGIOTIM LSTIOTIM MINIOTIM MAXIORTM MAXIOWTM
----- ------ ------- -------- --------- ------------ ------- -------- -------------- -------- -------- -------- -------- --------
    6     18      14       18        14           18       2        0              2        0        0        0        1        0
    7  57047  223616   535618    495511        42430   11588  5689141           4838        0        0        0      218      279

FILE# MILLI1 MILLI2 MILLI4 MILLI8 MILLI16 MILLI32 MILLI64 MILLI128 MILLI256 MILLI512 MILLI1024 MILLI2048 MILLI4096
----- ------ ------ ------ ------ ------- ------- ------- -------- -------- -------- --------- --------- ---------
    6      0      1      0      0       1       0       0        0        0        0         0         0         0
    7  39775    186    342    991     684     235     107       79        7        3         1         2         2

From the above:

18 SINGLEBLKRDS - Number of single block reads
18 PHYBLKRD - Number of physical blocks read
18 PHYRDS - Number of physical reads done

Don’t you hate it when Oracle is self-consistent, and yet at the same time not self-consistent?  One has to wonder if a bug was corrected regarding the counting of single block reads, or if direct path reads are no longer performed when the database is opened.  But, we have another problem – look closely at the output from V$FILE_HISTOGRAM.





Tracing Enabled for Sessions After Instance Restart

12 02 2010

February 12, 2010

An recent thread in the comp.databases.oracle.server Usenet group brought up an interesting question.  What would cause a 10046 trace at level 12 and and errorstack trace at level 3 for event 21700 to be enabled for sessions every time the original poster bounced the Oracle XE instance?  Is this possibly a sign that someone modified an initialization parameter?  Did someone modify the application to enabling tracing to log files?  Is it a bug in Oracle XE? 

Fortunately, the OP provided a portion of one of the trace files, as shown below:

*** SERVICE NAME:(SYS$USERS) 2010-02-02 09:46:36.593
*** SESSION ID:(31.46) 2010-02-02 09:46:36.593
=====================
PARSING IN CURSOR #6 len=69 dep=2 uid=0 oct=42 lid=0 tim=80934443123 hv=3164292706 ad='6688fd70'
alter session set events '10046 trace name context forever, level 12'
END OF STMT
EXEC #6:c=0,e=32,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=80934443118
=====================
PARSING IN CURSOR #6 len=71 dep=2 uid=0 oct=42 lid=0 tim=80934681241 hv=681663222 ad='6b8cb08c'
alter session set events '21700 trace name errorstack forever, level 3'
END OF STMT
PARSE #6:c=0,e=33,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=80934681236
BINDS #6:
EXEC #6:c=0,e=8426,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=80934748960
=====================
PARSING IN CURSOR #6 len=34 dep=2 uid=0 oct=42 lid=0 tim=80934753347 hv=1152259314 ad='66a0f058'
alter session set sql_trace = TRUE
END OF STMT
PARSE #6:c=0,e=59,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=80934753343
BINDS #6:
EXEC #6:c=0,e=29497,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=80934836162
=====================
PARSING IN CURSOR #7 len=435 dep=1 uid=0 oct=47 lid=0 tim=80934862347 hv=545826169 ad='6b897000'
begin
      execute immediate 'alter session set max_dump_file_size = unlimited';
      execute immediate 'alter session set tracefile_identifier = ''10046via_app''';
      execute immediate 'alter session set events ''10046 trace name context forever, level 12''';
      execute immediate 'alter session set events ''21700 trace name errorstack forever, level 3''';
      execute immediate 'alter session set sql_trace = TRUE';
  end;
END OF STMT

So, from the above trace file, is the tracing caused by:

  • A bug in Oracle XE
  • An application that was modified
  • A modified parameter in the spfile/pfile
  • None of the above

The number following dep= in the trace file is a significant clue.  SQL statements that are submitted by client application code will appear in 10046 trace files with dep= set to 0, so that probably rules out a change to the application code, unless of course the application is executing a PL/SQL block.  The discrete ALTER SESSION statements in the trace file that are wrapped in EXECUTE IMMEDIATE statements probably rules out the possibility of a parameter that was modified in the spfile/pfile and probably also rules out the possibilty of a bug in Oracle XE.  So, what might the next step be to find the cause of the trace files?

Another possibility is either a LOGON or STARTUP trigger that is enabling the trace.  The OP mentioned in the thread that he had enabled tracing earlier to troubleshoot a problem.  The tracing is apparently enabled in a PL/SQL procedure or anonymous PL/SQL block based on the value of dep= and the EXECUTE IMMEDIATE calls, so either a LOGON or STARTUP trigger is a possibility.  To test this possibility, you might execute a SQL statement like this:

SELECT
  TRIGGER_NAME,
  TRIGGER_TYPE,
  TRIGGERING_EVENT
FROM
  DBA_TRIGGERS
WHERE
  OWNER='SYS'
  AND TRIGGER_TYPE IN ('BEFORE EVENT','AFTER EVENT')
  AND SUBSTR(TRIGGERING_EVENT,1,5) IN ('START','LOGON');

TRIGGER_NAME           TRIGGER_TYPE TRIGGERING_EVENT
---------------------- ------------ ----------------
LOGON_FIX_MYAPP_PERF   AFTER EVENT  LOGON
LOGON_CAPTURE_10046    AFTER EVENT  LOGON
ENABLE_OUTLINES_TRIG   AFTER EVENT  STARTUP

If the above returned no rows, there is still a very small chance that a logon trigger or startup trigger is owned by a user other than SYS, so it might make sense to repeat the SQL statement without the OWNER=’SYS’ predicate in the WHERE clause.  In my case the SQL statement returned three rows – two logon triggers and one startup trigger.  The logon trigger name LOGON_CAPTURE_10046 is a significant indicator that a trigger is present that will enable a 10046 trace when the user logs into the database – it helps to use a consistent and descriptive naming convention.

The OP did not show the output of the above SQL statement, but did state that he found and removed a logon trigger that enabled the two traces.  If such a trigger is found, and you know that the trigger does not belong in the database, the trigger may be removed by connecting to the database as the SYS user and dropping the trigger:

DROP TRIGGER LOGON_CAPTURE_10046;




Automated DBMS_XPLAN, Trace, and Send to Excel

11 02 2010

February 11, 2010

If you have spent some time looking at the posts on this site you might have seen my Toy Project for performance tuning mentioned in a couple of those posts.  One of the windows in the program allows me to submit a SQL statement to the database and retrieve the execution plan using DBMS_XPLAN while simultaneously generating a 10046, 10053, 10032, or 10033 trace files.  That program window looks like this:

What would it take to implement something like the above using a VBS script with an Internet Explorer browser window acting at the user interface?  It might also be nice to have the ability to send the query results into Excel on demand.  The end result might look something like this (note that the array fetch setting might not have any effect):

If we use the sample tables from this blog post, what is the execution plan for the following SQL statement?

SELECT
  T3.C1 T3_C1,
  SUBSTR(T3.C2,1,10) T3_C2,
  T2.C1 T2_C1,
  SUBSTR(T2.C2,1,10) T2_C2,
  T1.C1 T1_C1,
  SUBSTR(T1.C2,1,10) T1_C2
FROM
  T3,
  T2,
  T1
WHERE
  T1.C1=T3.C1
  AND T1.C1=T2.C1
  AND T1.C1 BETWEEN 1 AND 10

If we submit the SQL statement with the TYPICAL format parameter specified, the following execution plan will appear (note that on Vista and Windows 7, the execution plan may hide behind the main window – a pop-under effect):

The first 100 rows from the SQL statement appear at the bottom of the window.  With the TYPICAL format parameter specified, we are only able to determine the estimated number of rows that will be returned, and the estimated execution time.

If we change the format parameter to ALLSTATS LAST and change the Statistics Level to ALL, we are able to see the actual execution statistics for the plan:

Of course at this point, we might wonder if nested loops joins might be more efficient than hash joins, so we could test the change in execution time with a hinted SQL statement:

Looking closely at the plans, we see that the plan with the hash joins completed in 4.31 seconds, while the plan with the nested loops joins completed in 5.0 seconds.  The cost-based optimizer correctly selected the fastest executing plan for the SQL statement.

We also have the option for enabling several types of trace files and determining what, if any, performance impact we see when various trace files are enabled:

Notice that the program assigned a unique trace filename (displayed on the Status line) so that it is easy to find the trace file for our test execution.

The final option on the web page sends the query results into an Excel workbook – do not close the Excel window until you first close the Internet Explorer window, a new worksheet will be created in the workbook every time the Send to Excel button is clicked:

If you want to experiment with this script, you may download it here: XPlanViewerWithTrace.vbs (version 1.0, save as XPlanViewerWithTrace.vbs).

—————————

Update February 18, 2010:

See the documentation for details of the permissions required to use DBMS_XPLAN.DISPLAY_CURSOR.  See comment #2 for the items that need to be changed in the script in order to connect to your database.





SQL – Determining if Resources are in Use in 2 Hour Time Periods

10 02 2010

February 10, 2010

A question appeared in the comp.databases.oracle.misc Usenet group a couple of years ago that caught my attention, and not just because the subject line read “need urgent help“.  The original poster supplied the following request:

I am creating attendance sheet software for in-house use.

my data is like this:

-----------------------------------------------------------------------
| name     |   login time                   |   logout time           |
-----------------------------------------------------------------------
|  a       |  2007-11-10 12:00:00           |  2007-11-10 16:00:00    |
-----------------------------------------------------------------------
|  b       |  2007-11-10 15:00:00           |  2007-11-10 18:00:00    |
-----------------------------------------------------------------------

My requirement:

I want to generate an hourly report like this:

----------------------------------------------------------
 date             time range        total people logged in
----------------------------------------------------------
 2007-11-10          0 -2                      0
----------------------------------------------------------
 2007-12-10          2-4                       0
----------------------------------------------------------
.
.
----------------------------------------------------------
 2007-11-10         12-14                      1
----------------------------------------------------------
 2007-11-10         14-16                      2
----------------------------------------------------------
 2007-11-10         16-18                      1
----------------------------------------------------------
.
.
----------------------------------------------------------
 2007-11-10         22-24                      0
----------------------------------------------------------

This is what I want to create, but I don’t know how can I generate such kind of report.

Ed Prochak offered the following advice in the thread, advice that is probably something that is easily forgotten when confronted by a simple problem that seems to be impossible to solve.

HINT: Try resolving the problem in steps.

The key to this is understanding that the result set of a SELECT can be considered a table. You may already have the first step you need, but basically try to think of the problem in parts.

If we were to apply Ed’s suggestions, we might start off by trying to simplify the problem with a test table, something like this:

CREATE TABLE T1 (
  USERNAME VARCHAR2(15),
  LOGIN_TIME DATE,
  LOGOUT_TIME DATE);

INSERT INTO
  T1
VALUES(
  'a',
  TO_DATE('2007-11-10 12:00','YYYY-MM-DD HH24:MI'),
  TO_DATE('2007-11-10 16:00','YYYY-MM-DD HH24:MI'));

INSERT INTO
  T1
VALUES(
  'b',
  TO_DATE('2007-11-10 15:00','YYYY-MM-DD HH24:MI'),
  TO_DATE('2007-11-10 18:00','YYYY-MM-DD HH24:MI'));

COMMIT;

At this point, we might start thinking about what, if any, potential problems we might encounter.  One of the challenges that we will face is working around the need to generate up to 12 rows (1 for each of the 2 hour long possible time periods) for each row in the source table.  A second problem is how to handle logins that occur before midnight, with a corresponding logout that occurs after midnight.  If it were known that there would be no time periods that cross midnight, we might try to build a solution like this using our test table:

SELECT
  TRUNC(LOGIN_TIME) CHECK_DATE,
  TO_NUMBER(TO_CHAR(LOGIN_TIME,'HH24')) LOGIN_HOUR,
  TO_NUMBER(TO_CHAR(LOGOUT_TIME,'HH24')) LOGOUT_HOUR
FROM
  T1;

CHECK_DAT LOGIN_HOUR LOGOUT_HOUR
--------- ---------- -----------
10-NOV-07         12          16
10-NOV-07         15          18

The above just simplifies the input table into dates, login hour and logout hour.

Next, we need a way to generate 12 rows.  We could just use an existing table, and specify that we want to return all rows where ROWNUM<=12, but we will use CONNECT BY LEVEL, which could result in greater CPU consumption, but would likely be more portable:

SELECT
  (LEVEL-1)*2 LOGIN_COUNTER,
  (LEVEL-1)*2+2 LOGOUT_COUNTER
FROM
  DUAL
CONNECT BY
  LEVEL<=12;

LOGIN_COUNTER LOGOUT_COUNTER
------------- --------------
            0              2
            2              4
            4              6
            6              8
            8             10
           10             12
           12             14
           14             16
           16             18
           18             20
           20             22
           22             24

Now that we have the two simplified data sets, we just need to find where the two data sets intersect.  First, let’s find those records where the numbers from the counter fall between the LOGIN_HOUR and the LOGOUT_HOUR:

SELECT
  T.CHECK_DATE,
  T.LOGIN_HOUR,
  T.LOGOUT_HOUR,
  TO_CHAR(LOGIN_COUNTER,'99')||'-'||TO_CHAR(LOGOUT_COUNTER,'99') TIME_RANGE
FROM
  (SELECT
    TRUNC(LOGIN_TIME) CHECK_DATE,
    TO_NUMBER(TO_CHAR(LOGIN_TIME,'HH24')) LOGIN_HOUR,
    TO_NUMBER(TO_CHAR(LOGOUT_TIME,'HH24')) LOGOUT_HOUR
  FROM
    T1) T,
  (SELECT
    (LEVEL-1)*2 LOGIN_COUNTER,
    (LEVEL-1)*2+2 LOGOUT_COUNTER
  FROM
    DUAL
  CONNECT BY
    LEVEL<=12) C
WHERE
  C.LOGIN_COUNTER BETWEEN T.LOGIN_HOUR AND T.LOGOUT_HOUR
  AND C.LOGOUT_COUNTER BETWEEN T.LOGIN_HOUR AND T.LOGOUT_HOUR
ORDER BY
  1,
  4,
  2;

CHECK_DAT LOGIN_HOUR LOGOUT_HOUR TIME_RA
--------- ---------- ----------- -------
10-NOV-07         12          16  12- 14
10-NOV-07         12          16  14- 16
10-NOV-07         15          18  16- 18

You may notice that the above output is missing one row.  Let’s see if we can find a way to include the missing row:

SELECT
  T.CHECK_DATE,
  T.LOGIN_HOUR,
  T.LOGOUT_HOUR,
  TO_CHAR(LOGIN_COUNTER,'99')||'-'||TO_CHAR(LOGOUT_COUNTER,'99') TIME_RANGE
FROM
  (SELECT
    TRUNC(LOGIN_TIME) CHECK_DATE,
    TO_NUMBER(TO_CHAR(LOGIN_TIME,'HH24')) LOGIN_HOUR,
    TO_NUMBER(TO_CHAR(LOGOUT_TIME,'HH24')) LOGOUT_HOUR
  FROM
    T1) T,
  (SELECT
    (LEVEL-1)*2 LOGIN_COUNTER,
    (LEVEL-1)*2+2 LOGOUT_COUNTER
  FROM
    DUAL
  CONNECT BY
    LEVEL<=12) C
WHERE
  (C.LOGIN_COUNTER BETWEEN T.LOGIN_HOUR AND T.LOGOUT_HOUR
    AND C.LOGOUT_COUNTER BETWEEN T.LOGIN_HOUR AND T.LOGOUT_HOUR)
  OR T.LOGIN_HOUR BETWEEN C.LOGIN_COUNTER AND C.LOGOUT_COUNTER-1
  OR T.LOGOUT_HOUR BETWEEN C.LOGIN_COUNTER+1 AND C.LOGOUT_COUNTER
ORDER BY
  1,
  4,
  2;

CHECK_DAT LOGIN_HOUR LOGOUT_HOUR TIME_RA
--------- ---------- ----------- -------
10-NOV-07         12          16  12- 14
10-NOV-07         12          16  14- 16
10-NOV-07         15          18  14- 16
10-NOV-07         15          18  16- 18

By also allowing the LOGIN_HOUR to fall between the LOGIN_COUNTER and LOGOUT_COUNTER, or the LOGOUT_HOUR to fall between the LOGIN_COUNTER and LOGOUT_COUNTER (with a slight adjustment), we pick up the missing row.  Now, it is a simple matter to find the total number in each time period by sliding the above into an inline view:

SELECT
  T.CHECK_DATE,
  TO_CHAR(LOGIN_COUNTER,'99')||'-'||TO_CHAR(LOGOUT_COUNTER,'99') TIME_RANGE,
  COUNT(*) TOTAL_PEOPLE
FROM
  (SELECT
    TRUNC(LOGIN_TIME) CHECK_DATE,
    TO_NUMBER(TO_CHAR(LOGIN_TIME,'HH24')) LOGIN_HOUR,
    TO_NUMBER(TO_CHAR(LOGOUT_TIME,'HH24')) LOGOUT_HOUR
  FROM
    T1) T,
  (SELECT
    (LEVEL-1)*2 LOGIN_COUNTER,
    (LEVEL-1)*2+2 LOGOUT_COUNTER
  FROM
    DUAL
  CONNECT BY
    LEVEL<=12) C
WHERE
  (C.LOGIN_COUNTER BETWEEN T.LOGIN_HOUR AND T.LOGOUT_HOUR
    AND C.LOGOUT_COUNTER BETWEEN T.LOGIN_HOUR AND T.LOGOUT_HOUR)
  OR T.LOGIN_HOUR BETWEEN C.LOGIN_COUNTER AND C.LOGOUT_COUNTER-1
  OR T.LOGOUT_HOUR BETWEEN C.LOGIN_COUNTER+1 AND C.LOGOUT_COUNTER
GROUP BY
  T.CHECK_DATE,
  TO_CHAR(LOGIN_COUNTER,'99')||'-'||TO_CHAR(LOGOUT_COUNTER,'99')
ORDER BY
  1,
  2;

CHECK_DAT TIME_RA TOTAL_PEOPLE
--------- ------- ------------
10-NOV-07  12- 14            1
10-NOV-07  14- 16            2
10-NOV-07  16- 18            1

The above SQL statement is likely not the only solution to the problem.  Let’s take another look at the problem.  What if there is a need for the time intervals to cross midnight.  We need to make a couple of adjustments.  First, let’s add another row to the table for variety:

INSERT INTO
  T1
VALUES(
  'c',
  TO_DATE('2007-11-10 13:00','YYYY-MM-DD HH24:MI'),
  TO_DATE('2007-11-10 19:00','YYYY-MM-DD HH24:MI'));

We can start with the SELECT statement we used earlier:

SELECT
  LOGIN_TIME,
  TO_NUMBER(TO_CHAR(LOGIN_TIME,'HH24')) LOGIN_HOUR,
  TO_NUMBER(TO_CHAR(LOGOUT_TIME,'HH24')) LOGOUT_HOUR
FROM
  T1;

LOGIN_TIM LOGIN_HOUR LOGOUT_HOUR
--------- ---------- -----------
10-NOV-07         12          16
10-NOV-07         15          18
10-NOV-07         13          19

We will modified the SQL statement above to produce the same output, with a little bit more efficiency:

SELECT
  LOGIN_TIME,
  (LOGIN_TIME-TRUNC(LOGIN_TIME))*24 LOGIN_HOUR,
  (LOGOUT_TIME-TRUNC(LOGOUT_TIME))*24 LOGOUT_HOUR
FROM
  T1;

LOGIN_TIM LOGIN_HOUR LOGOUT_HOUR
--------- ---------- -----------
10-NOV-07         12          16
10-NOV-07         15          18
10-NOV-07         13          19

Now, we need to round the clock in and clock out times to two hour intervals – note that the LOGOUT_HOUR_A value of the last row was rounded up:

SELECT
  LOGIN_TIME,
  (LOGIN_TIME-TRUNC(LOGIN_TIME))*24 LOGIN_HOUR,
  (LOGOUT_TIME-TRUNC(LOGOUT_TIME))*24 LOGOUT_HOUR,
  FLOOR((LOGIN_TIME-TRUNC(LOGIN_TIME))*24/2)*2 LOGIN_HOUR_A,
  CEIL((LOGOUT_TIME-TRUNC(LOGOUT_TIME))*24/2)*2 LOGOUT_HOUR_A
FROM
  T1;

LOGIN_TIM LOGIN_HOUR LOGOUT_HOUR LOGIN_HOUR_A LOGOUT_HOUR_A
--------- ---------- ----------- ------------ -------------
10-NOV-07         12          16           12            16
10-NOV-07         15          18           14            18
10-NOV-07         13          19           12            20

Let’s take the above hours and translate them back into date/time values and determine the number of intervals between the adjusted LOGIN_HOUR_A and LOGOUT_HOUR_A:

SELECT
  LOGIN_TIME,
  LOGOUT_TIME,
  TRUNC(LOGIN_TIME)+(FLOOR((LOGIN_TIME-TRUNC(LOGIN_TIME))*24/2)*2)/24 LOGIN_HOUR_A,
  TRUNC(LOGOUT_TIME)+(CEIL((LOGOUT_TIME-TRUNC(LOGOUT_TIME))*24/2)*2)/24 LOGOUT_HOUR_A,
  ((TRUNC(LOGOUT_TIME)+(CEIL((LOGOUT_TIME-TRUNC(LOGOUT_TIME))*24/2)*2)/24)
    - (TRUNC(LOGIN_TIME)+(FLOOR((LOGIN_TIME-TRUNC(LOGIN_TIME))*24/2)*2)/24))*12 H
FROM
  T1;

LOGIN_TIME           LOGOUT_TIME          LOGIN_HOUR_A         LOGOUT_HOUR_A        H
-------------------- -------------------- -------------------- -------------------- -
10-NOV-2007 12:00:00 10-NOV-2007 16:00:00 10-NOV-2007 12:00:00 10-NOV-2007 16:00:00 2
10-NOV-2007 15:00:00 10-NOV-2007 18:00:00 10-NOV-2007 14:00:00 10-NOV-2007 18:00:00 2
10-NOV-2007 13:00:00 10-NOV-2007 19:00:00 10-NOV-2007 12:00:00 10-NOV-2007 20:00:00 4

We then combine the above with a simple counter that counts from 1 up to 12, only joining those rows from the counter that are less than or equal to the calculated number of intervals.  By adding the number of hours determined by the counter to the adjusted LOGIN_HOUR_A, values we obtain the time intervals:

SELECT
  T.LOGIN_TIME,
  T.LOGOUT_TIME,
  T.LOGIN_HOUR_A+(C.COUNTER*2-2)/24 TIME_START,
  T.LOGIN_HOUR_A+(C.COUNTER*2)/24 TIME_END
FROM
  (SELECT
    LOGIN_TIME,
    LOGOUT_TIME,
    TRUNC(LOGIN_TIME)+(FLOOR((LOGIN_TIME-TRUNC(LOGIN_TIME))*24/2)*2)/24 LOGIN_HOUR_A,
    TRUNC(LOGOUT_TIME)+(CEIL((LOGOUT_TIME-TRUNC(LOGOUT_TIME))*24/2)*2)/24 LOGOUT_HOUR_A,
    ((TRUNC(LOGOUT_TIME)+(CEIL((LOGOUT_TIME-TRUNC(LOGOUT_TIME))*24/2)*2)/24)
     - (TRUNC(LOGIN_TIME)+(FLOOR((LOGIN_TIME-TRUNC(LOGIN_TIME))*24/2)*2)/24))*12 H
  FROM
    T1) T,
  (SELECT
    LEVEL COUNTER
  FROM
    DUAL
  CONNECT BY
    LEVEL<=12) C
WHERE
  T.H>=C.COUNTER;

LOGIN_TIME           LOGOUT_TIME          TIME_START           TIME_END
==================== ==================== ==================== ====================
10-NOV-2007 12:00:00 10-NOV-2007 16:00:00 10-NOV-2007 12:00:00 10-NOV-2007 14:00:00
10-NOV-2007 15:00:00 10-NOV-2007 18:00:00 10-NOV-2007 14:00:00 10-NOV-2007 16:00:00
10-NOV-2007 13:00:00 10-NOV-2007 19:00:00 10-NOV-2007 12:00:00 10-NOV-2007 14:00:00
10-NOV-2007 12:00:00 10-NOV-2007 16:00:00 10-NOV-2007 14:00:00 10-NOV-2007 16:00:00
10-NOV-2007 15:00:00 10-NOV-2007 18:00:00 10-NOV-2007 16:00:00 10-NOV-2007 18:00:00
10-NOV-2007 13:00:00 10-NOV-2007 19:00:00 10-NOV-2007 14:00:00 10-NOV-2007 16:00:00
10-NOV-2007 13:00:00 10-NOV-2007 19:00:00 10-NOV-2007 16:00:00 10-NOV-2007 18:00:00
10-NOV-2007 13:00:00 10-NOV-2007 19:00:00 10-NOV-2007 18:00:00 10-NOV-2007 20:00:00

The final step is to perform a group by:

SELECT
  CHECK_DATE,
  TO_CHAR(TIME_START,'HH24')||'-'||TO_CHAR(TIME_END,'HH24') TIME_RANGE,
  COUNT(*) TOTAL_PEOPLE
FROM
(SELECT
  TRUNC(T.LOGIN_HOUR_A+(C.COUNTER*2-2)/24) CHECK_DATE,
  T.LOGIN_HOUR_A+(C.COUNTER*2-2)/24 TIME_START,
  T.LOGIN_HOUR_A+(C.COUNTER*2)/24 TIME_END
FROM
  (SELECT
    LOGIN_TIME,
    LOGOUT_TIME,
    TRUNC(LOGIN_TIME)+(FLOOR((LOGIN_TIME-TRUNC(LOGIN_TIME))*24/2)*2)/24 LOGIN_HOUR_A,
    TRUNC(LOGOUT_TIME)+(CEIL((LOGOUT_TIME-TRUNC(LOGOUT_TIME))*24/2)*2)/24 LOGOUT_HOUR_A,
    ((TRUNC(LOGOUT_TIME)+(CEIL((LOGOUT_TIME-TRUNC(LOGOUT_TIME))*24/2)*2)/24)
     - (TRUNC(LOGIN_TIME)+(FLOOR((LOGIN_TIME-TRUNC(LOGIN_TIME))*24/2)*2)/24))*12 H
  FROM
    T1) T,
  (SELECT
    LEVEL COUNTER
  FROM
    DUAL
  CONNECT BY
    LEVEL<=12) C
WHERE
  T.H>=C.COUNTER)
GROUP BY
  CHECK_DATE,
  TO_CHAR(TIME_START,'HH24')||'-'||TO_CHAR(TIME_END,'HH24')
ORDER BY
  1,
  2;

CHECK_DAT TIME_ TOTAL_PEOPLE
--------- ----- ------------
10-NOV-07 12-14            2
10-NOV-07 14-16            3
10-NOV-07 16-18            2
10-NOV-07 18-20            1

Now that we know that the above approach provides the desired results with the existing data, let’s add a row to the table where the values cross midnight:

INSERT INTO
  T1
VALUES(
  'c',
  TO_DATE('2007-11-10 19:00','YYYY-MM-DD HH24:MI'),
  TO_DATE('2007-11-11 04:00','YYYY-MM-DD HH24:MI'));

The results of our final SQL statement look like this following:

CHECK_DAT TIME_ TOTAL_PEOPLE
--------- ----- ------------
10-NOV-07 12-14            2
10-NOV-07 14-16            3
10-NOV-07 16-18            2
10-NOV-07 18-20            2
10-NOV-07 20-22            1
10-NOV-07 22-00            1
11-NOV-07 00-02            1
11-NOV-07 02-04            1

I don’t think that anyone mentioned it in the Usenet thread, but Ed Prochak’s suggestion was correct.  It does not matter much if someone is trying to solve an algebra problem (or even manually attempting to solve a long division problem), a performance tuning problem, or a SQL related problem – what is required is a logical, step-by-step approach to tackling the problem, with each step moving closer to the end result.





Working with Oracle’s Time Model Data 3

9 02 2010

February 9, 2010

(Back to the Previous Post in the Series)

 In the previous article in this series, we created a structured view of the V$SYS_TIME_MODEL view:
 

Then on demand brought in session level detail for the same statistics so that it was possible to investigate why a statistic value continued to grow.  The previous article also displayed delta values from V$OSSTAT and the wait events from V$SYSTEM_EVENT.  It appears that a couple people liked the previous effort, and I gave serious thought to having the computer provide audio feedback when a session started consuming a lot of resources – but then I started to wonder if maybe we should instead have an audio warning when a session is consuming less than the average resource consumption so that we could then determine who is reading this article rather than working. 🙂  In the end, I decided to leave out the audio feedback.  So, what else can we do with the framework that was provided in the second article of this series?

It might be nice to be able to drill into session-level wait events to determine why a wait event’s time delta keeps growing, maybe by adding a couple of extra buttons to the web page that is created on the fly by the VBS script:

It might also be nice to be able to view the DBMS_XPLAN for a query that was identified as a SQL statement that was recently executed by a session.  One of the problems with the original script is that it only retrieved the SQL_ID and SQL_CHILD_NUMBER from V$SESSION, and it seemed that those columns contained NULL values just as frequently as they contained data.  The updated script will attempt to return the PREV_SQL_ID and PREV_CHILD_NUMBER columns if the other two columns contain NULL values.  In addition to retrieving the DBMS_XPLAN for the CHILD_NUMBER that is executed by the session, it might also be helpful to retrieve the DBMS_XPLAN for all child cursors for a given SQL_ID so that we are able to determine if the execution plan changed, and why it changed.  While we are at it, let’s make it possible to enable a 10046 extended SQL trace for a session just by clicking a button on the web page.  With the changes to the script, the generated web page might look something like this (note that this is a touched up image – the computer name and username were erased):

Scrolling down to the bottom of the page, note that the Session Waits button for the db file scattered read wait event was clicked:

 So, what happens if one of the XPlan buttons is clicked?  We could just write the execution plan to a text file, but where is the fun in doing that?  How about popping up another web browser page that lists all execution plans for a query that are currently in the library cache, the reasons for those generated execution plans from V$SQL_SHARED_CURSOR, and the bind variable definitions from V$SQL_BIND_METADATA.  The generated web page might look something like this (with duplicate sections from the different child cursors removed to save space):

**********************************************************************************************
Reason for Child Cursor Creation
BIND_MISMATCH
LOAD_OPTIMIZER_STATS
**********
Bind Variable Definitions
  Position:1  Max Length:32  VARCHAR2  Name:1
**********
SQL_ID  8p3pacrbngv80, child number 1
-------------------------------------
SELECT DISTINCT    R.PART_ID,    P.FABRICATED,    P.PURCHASED  FROM    
WORK_ORDER WO,    REQUIREMENT R,    PART P  WHERE  
  WO.TYPE='W'    AND WO.SUB_ID='0'    AND WO.STATUS IN ('F','R','U')    
AND WO.DESIRED_QTY>WO.RECEIVED_QTY    AND WO.PART_ID= :1    AND 
R.WORKORDER_TYPE='W'    AND WO.TYPE=R.WORKORDER_TYPE    AND 
WO.BASE_ID=R.WORKORDER_BASE_ID    AND WO.LOT_ID=R.WORKORDER_LOT_ID    
AND WO.SPLIT_ID=R.WORKORDER_SPLIT_ID    AND R.SUBORD_WO_SUB_ID IS NULL  
  AND R.CALC_QTY>R.ISSUED_QTY    AND R.PART_ID=P.ID  ORDER BY    
R.PART_ID

Plan hash value: 3990487722

------------------------------------------------------------------------------------------------------------
| Id  | Operation                       | Name            | Rows  | Bytes | Cost (%CPU)| Time     | Inst   |
------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                |                 |       |       |    27 (100)|          |        |
|   1 |  SORT UNIQUE                    |                 |     9 |   747 |    26   (4)| 00:00:01 |        |
|   2 |   NESTED LOOPS                  |                 |       |       |            |          |        |
|   3 |    NESTED LOOPS                 |                 |     9 |   747 |    25   (0)| 00:00:01 |        |
|   4 |     NESTED LOOPS                |                 |     9 |   621 |    16   (0)| 00:00:01 |        |
|*  5 |      TABLE ACCESS BY INDEX ROWID| WORK_ORDER      |     1 |    37 |    13   (0)| 00:00:01 |   OR11 |
|*  6 |       INDEX RANGE SCAN          | X_WORK_ORDER_1  |    21 |       |     3   (0)| 00:00:01 |   OR11 |
|*  7 |      TABLE ACCESS BY INDEX ROWID| REQUIREMENT     |    25 |   800 |     3   (0)| 00:00:01 |   OR11 |
|*  8 |       INDEX RANGE SCAN          | X_REQUIREMENT_5 |     1 |       |     2   (0)| 00:00:01 |   OR11 |
|*  9 |     INDEX UNIQUE SCAN           | SYS_C0011459    |     1 |       |     0   (0)|          |   OR11 |
|  10 |    TABLE ACCESS BY INDEX ROWID  | PART            |     1 |    14 |     1   (0)| 00:00:01 |   OR11 |
------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   5 - filter(("WO"."DESIRED_QTY">"WO"."RECEIVED_QTY" AND "WO"."SUB_ID"='0' AND 
              INTERNAL_FUNCTION("WO"."STATUS") AND "WO"."TYPE"='W'))
   6 - access("WO"."PART_ID"=:1)
   7 - filter("R"."CALC_QTY">"R"."ISSUED_QTY")
   8 - access("WO"."TYPE"="R"."WORKORDER_TYPE" AND "WO"."BASE_ID"="R"."WORKORDER_BASE_ID" AND 
              "WO"."LOT_ID"="R"."WORKORDER_LOT_ID" AND "WO"."SPLIT_ID"="R"."WORKORDER_SPLIT_ID" AND 
              "R"."SUBORD_WO_SUB_ID" IS NULL)
       filter("R"."WORKORDER_TYPE"='W')
   9 - access("R"."PART_ID"="P"."ID")

**********************************************************************************************
Reason for Child Cursor Creation
BIND_MISMATCH
ROW_LEVEL_SEC_MISMATCH
**********
Bind Variable Definitions
  Position:1  Max Length:32  VARCHAR2  Name:1
**********
SQL_ID  8p3pacrbngv80, child number 2
-------------------------------------
SELECT DISTINCT    R.PART_ID,    P.FABRICATED,    P.PURCHASED  FROM    
...
Plan hash value: 3990487722

------------------------------------------------------------------------------------------------------------
| Id  | Operation                       | Name            | Rows  | Bytes | Cost (%CPU)| Time     | Inst   |
------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                |                 |       |       |    27 (100)|          |        |
|   1 |  SORT UNIQUE                    |                 |     9 |   747 |    26   (4)| 00:00:01 |        |
|   2 |   NESTED LOOPS                  |                 |       |       |            |          |        |
|   3 |    NESTED LOOPS                 |                 |     9 |   747 |    25   (0)| 00:00:01 |        |
|   4 |     NESTED LOOPS                |                 |     9 |   621 |    16   (0)| 00:00:01 |        |
|*  5 |      TABLE ACCESS BY INDEX ROWID| WORK_ORDER      |     1 |    37 |    13   (0)| 00:00:01 |   OR11 |
|*  6 |       INDEX RANGE SCAN          | X_WORK_ORDER_1  |    21 |       |     3   (0)| 00:00:01 |   OR11 |
|*  7 |      TABLE ACCESS BY INDEX ROWID| REQUIREMENT     |    25 |   800 |     3   (0)| 00:00:01 |   OR11 |
|*  8 |       INDEX RANGE SCAN          | X_REQUIREMENT_5 |     1 |       |     2   (0)| 00:00:01 |   OR11 |
|*  9 |     INDEX UNIQUE SCAN           | SYS_C0011459    |     1 |       |     0   (0)|          |   OR11 |
|  10 |    TABLE ACCESS BY INDEX ROWID  | PART            |     1 |    14 |     1   (0)| 00:00:01 |   OR11 |
------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   5 - filter(("WO"."DESIRED_QTY">"WO"."RECEIVED_QTY" AND "WO"."SUB_ID"='0' AND 
              INTERNAL_FUNCTION("WO"."STATUS") AND "WO"."TYPE"='W'))
   6 - access("WO"."PART_ID"=:1)
   7 - filter("R"."CALC_QTY">"R"."ISSUED_QTY")
   8 - access("WO"."TYPE"="R"."WORKORDER_TYPE" AND "WO"."BASE_ID"="R"."WORKORDER_BASE_ID" AND 
              "WO"."LOT_ID"="R"."WORKORDER_LOT_ID" AND "WO"."SPLIT_ID"="R"."WORKORDER_SPLIT_ID" AND 
              "R"."SUBORD_WO_SUB_ID" IS NULL)
       filter("R"."WORKORDER_TYPE"='W')
   9 - access("R"."PART_ID"="P"."ID")

**********************************************************************************************
Reason for Child Cursor Creation
BIND_MISMATCH
ROW_LEVEL_SEC_MISMATCH
**********
Bind Variable Definitions
  Position:1  Max Length:32  VARCHAR2  Name:1
**********
SQL_ID  8p3pacrbngv80, child number 3
-------------------------------------
SELECT DISTINCT    R.PART_ID,    P.FABRICATED,    P.PURCHASED  FROM    
...

**********************************************************************************************
Reason for Child Cursor Creation
BIND_MISMATCH
LOAD_OPTIMIZER_STATS
**********
Bind Variable Definitions
  Position:1  Max Length:32  VARCHAR2  Name:1
**********
SQL_ID  8p3pacrbngv80, child number 4
-------------------------------------
SELECT DISTINCT    R.PART_ID,    P.FABRICATED,    P.PURCHASED  FROM    
...

**********************************************************************************************
Reason for Child Cursor Creation
BIND_MISMATCH
ROW_LEVEL_SEC_MISMATCH
**********
Bind Variable Definitions
  Position:1  Max Length:32  VARCHAR2  Name:1
**********
SQL_ID  8p3pacrbngv80, child number 5
-------------------------------------
SELECT DISTINCT    R.PART_ID,    P.FABRICATED,    P.PURCHASED  FROM    
...
 
**********************************************************************************************
Reason for Child Cursor Creation
BIND_MISMATCH
ROW_LEVEL_SEC_MISMATCH
**********
Bind Variable Definitions
  Position:1  Max Length:32  VARCHAR2  Name:1
**********
SQL_ID  8p3pacrbngv80, child number 7
-------------------------------------
SELECT DISTINCT    R.PART_ID,    P.FABRICATED,    P.PURCHASED  FROM    
...
Plan hash value: 1336181825

------------------------------------------------------------------------------------------------------------------
| Id  | Operation                             | Name            | Rows  | Bytes | Cost (%CPU)| Time     | Inst   |
------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                      |                 |       |       |   577 (100)|          |        |
|   1 |  SORT UNIQUE                          |                 |   838 | 69554 |   576   (1)| 00:00:07 |        |
|*  2 |   HASH JOIN                           |                 |   838 | 69554 |   575   (1)| 00:00:07 |        |
|   3 |    NESTED LOOPS                       |                 |       |       |            |          |        |
|   4 |     NESTED LOOPS                      |                 |   840 | 57960 |   164   (0)| 00:00:02 |        |
|*  5 |      TABLE ACCESS BY INDEX ROWID      | WORK_ORDER      |    35 |  1295 |    60   (0)| 00:00:01 |   OR11 |
|   6 |       BITMAP CONVERSION TO ROWIDS     |                 |       |       |            |          |        |
|   7 |        BITMAP AND                     |                 |       |       |            |          |        |
|   8 |         BITMAP CONVERSION FROM ROWIDS |                 |       |       |            |          |        |
|*  9 |          INDEX RANGE SCAN             | X_WORK_ORDER_1  | 13721 |       |     8   (0)| 00:00:01 |   OR11 |
|  10 |         BITMAP OR                     |                 |       |       |            |          |        |
|  11 |          BITMAP CONVERSION FROM ROWIDS|                 |       |       |            |          |        |
|* 12 |           INDEX RANGE SCAN            | X_WORK_ORDER_2  | 13721 |       |     6   (0)| 00:00:01 |   OR11 |
|  13 |          BITMAP CONVERSION FROM ROWIDS|                 |       |       |            |          |        |
|* 14 |           INDEX RANGE SCAN            | X_WORK_ORDER_2  | 13721 |       |     1   (0)| 00:00:01 |   OR11 |
|  15 |          BITMAP CONVERSION FROM ROWIDS|                 |       |       |            |          |        |
|* 16 |           INDEX RANGE SCAN            | X_WORK_ORDER_2  | 13721 |       |    19   (0)| 00:00:01 |   OR11 |
|* 17 |      INDEX RANGE SCAN                 | X_REQUIREMENT_5 |     1 |       |     2   (0)| 00:00:01 |   OR11 |
|* 18 |     TABLE ACCESS BY INDEX ROWID       | REQUIREMENT     |    24 |   768 |     3   (0)| 00:00:01 |   OR11 |
|  19 |    TABLE ACCESS FULL                  | PART            | 37032 |   506K|   410   (1)| 00:00:05 |   OR11 |
------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("R"."PART_ID"="P"."ID")
   5 - filter(("WO"."DESIRED_QTY">"WO"."RECEIVED_QTY" AND "WO"."SUB_ID"='0' AND "WO"."TYPE"='W'))
   9 - access("WO"."PART_ID"=:1)
  12 - access("WO"."STATUS"='F')
  14 - access("WO"."STATUS"='R')
  16 - access("WO"."STATUS"='U')
  17 - access("WO"."TYPE"="R"."WORKORDER_TYPE" AND "WO"."BASE_ID"="R"."WORKORDER_BASE_ID" AND 
              "WO"."LOT_ID"="R"."WORKORDER_LOT_ID" AND "WO"."SPLIT_ID"="R"."WORKORDER_SPLIT_ID" AND 
              "R"."SUBORD_WO_SUB_ID" IS NULL)
       filter("R"."WORKORDER_TYPE"='W')
  18 - filter("R"."CALC_QTY">"R"."ISSUED_QTY")

**********************************************************************************************
Reason for Child Cursor Creation
BIND_MISMATCH
**********
Bind Variable Definitions
  Position:1  Max Length:32  VARCHAR2  Name:1
**********
SQL_ID  8p3pacrbngv80, child number 8
-------------------------------------
SELECT DISTINCT    R.PART_ID,    P.FABRICATED,    P.PURCHASED  FROM    
SYSADM.WORK_ORDER WO,    SYSADM.REQUIREMENT R,    SYSADM.PART P  WHERE  
  WO.TYPE='W'    AND WO.SUB_ID='0'    AND WO.STATUS IN ('F','R','U')    
AND WO.DESIRED_QTY>WO.RECEIVED_QTY    AND WO.PART_ID= :1    AND 
R.WORKORDER_TYPE='W'    AND WO.TYPE=R.WORKORDER_TYPE    AND 
WO.BASE_ID=R.WORKORDER_BASE_ID    AND WO.LOT_ID=R.WORKORDER_LOT_ID    
AND WO.SPLIT_ID=R.WORKORDER_SPLIT_ID    AND R.SUBORD_WO_SUB_ID IS NULL  
  AND R.CALC_QTY>R.ISSUED_QTY    AND R.PART_ID=P.ID  ORDER BY    
R.PART_ID

Plan hash value: 3990487722

------------------------------------------------------------------------------------------------------------
| Id  | Operation                       | Name            | Rows  | Bytes | Cost (%CPU)| Time     | Inst   |
------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                |                 |       |       |    27 (100)|          |        |
|   1 |  SORT UNIQUE                    |                 |     9 |   747 |    26   (4)| 00:00:01 |        |
|   2 |   NESTED LOOPS                  |                 |       |       |            |          |        |
|   3 |    NESTED LOOPS                 |                 |     9 |   747 |    25   (0)| 00:00:01 |        |
|   4 |     NESTED LOOPS                |                 |     9 |   621 |    16   (0)| 00:00:01 |        |
|*  5 |      TABLE ACCESS BY INDEX ROWID| WORK_ORDER      |     1 |    37 |    13   (0)| 00:00:01 |   OR11 |
|*  6 |       INDEX RANGE SCAN          | X_WORK_ORDER_1  |    21 |       |     3   (0)| 00:00:01 |   OR11 |
|*  7 |      TABLE ACCESS BY INDEX ROWID| REQUIREMENT     |    24 |   768 |     3   (0)| 00:00:01 |   OR11 |
|*  8 |       INDEX RANGE SCAN          | X_REQUIREMENT_5 |     1 |       |     2   (0)| 00:00:01 |   OR11 |
|*  9 |     INDEX UNIQUE SCAN           | SYS_C0011459    |     1 |       |     0   (0)|          |   OR11 |
|  10 |    TABLE ACCESS BY INDEX ROWID  | PART            |     1 |    14 |     1   (0)| 00:00:01 |   OR11 |
------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   5 - filter(("WO"."DESIRED_QTY">"WO"."RECEIVED_QTY" AND "WO"."SUB_ID"='0' AND 
              INTERNAL_FUNCTION("WO"."STATUS") AND "WO"."TYPE"='W'))
   6 - access("WO"."PART_ID"=:1)
   7 - filter("R"."CALC_QTY">"R"."ISSUED_QTY")
   8 - access("WO"."TYPE"="R"."WORKORDER_TYPE" AND "WO"."BASE_ID"="R"."WORKORDER_BASE_ID" AND 
              "WO"."LOT_ID"="R"."WORKORDER_LOT_ID" AND "WO"."SPLIT_ID"="R"."WORKORDER_SPLIT_ID" AND 
              "R"."SUBORD_WO_SUB_ID" IS NULL)
       filter("R"."WORKORDER_TYPE"='W')
   9 - access("R"."PART_ID"="P"."ID")

**********************************************************************************************
Reason for Child Cursor Creation
BIND_MISMATCH
LOAD_OPTIMIZER_STATS
**********
Bind Variable Definitions
  Position:1  Max Length:32  VARCHAR2  Name:1
**********
SQL_ID  8p3pacrbngv80, child number 9
-------------------------------------
SELECT DISTINCT    R.PART_ID,    P.FABRICATED,    P.PURCHASED  FROM    
...
**********************************************************************************************

In the above, the selected session was actually using the execution plan for child number 3.  Notice that one of the execution plans converted normal B*Tree indexes on the fly to permit comparisons much like what are possible with bitmap indexes.  A large portion of the execution plans were created, at least in part, because of a bind mismatch – see the documentation V$SQL_SHARED_CURSOR for more information.

This example requires at a minimum Oracle Database 10.1.0.1 running on Windows, Unix, or Linux.  The supplied script must be run from a Windows client computer.  You will need to specify a suitable username, password, and database name (from tnsnames.ora) for the strUsername, strPassword, and strDatabase variables in the VBS script.  This script ties into several of the chapters in the Expert Oracle Practices book.

Download the script from here: MonitorDatabaseTimeModel.vbs (save as MonitorDatabaseTimeModel.vbs, without the .doc extension – note that this is version 2.0.1)





Slow Query with an Interesting Execution Plan

8 02 2010

February 8, 2010

In one of the recent Oracle forums threads a person reported experiencing performance problems with a particular query, and in an atypical fashion, the original poster also provided an explain plan for the SQL statement, and stated their database release.
http://forums.oracle.com/forums/thread.jspa?messageID=4068085

A slightly reformatted version of the SQL statement looked like this:

SELECT
  A.BROKER_NAME,
  A.PARENT_BROKER_CODE,
  MAX(C.LAST_UPDATE_DATE) as LAST_SUBMISSION_DATE,
  BROKER_CODE as CHILD_BROKER_CODE,
  d.LOCATION
FROM
  CM_CACHE_BROKER a,
  REM_TAG_VALUE b,
  CM_ENUM_TAG c,
  CM_CACHE_BROKER_detail d
WHERE
  A.PARENT_BROKER_CODE = B.TAG_VALUE
  AND EXISTS
    (SELECT
      1
    FROM
      REM_TAG_LIST d
    WHERE
      D.TAG_LIST_ID = B.TAG_LIST_ID
      AND D.TAG_LIST_CODE = 'FCBrokerCode')
  AND B.TAG_VALUE_ID = C.TAG_VALUE_ID
  AND a.BROKER_ID=d.BROKER_ID
GROUP BY
  BROKER_NAME,
  PARENT_BROKER_CODE,
  BROKER_CODE,
  location
order by
  BROKER_NAME;

Just from looking at the SQL statement, we start seeing a couple of problems:

  • Not all of the columns are aliased – which table are those columns coming from?
  • The table aliases are confusingly assigned – what tables are involved with this predicate: “a.BROKER_ID=d.BROKER_ID”
  • The table in the EXISTS subquery, REM_TAG_LIST, uses the same alias “D” as the CM_CACHE_BROKER_detail table in the main section of the query, so looking at the Predicate Information section of a DBMS_XPLAN output could be confusing.  A recent article on another blog offers suggestions for improving the readability of table aliases.

The original poster in the thread provided an interesting execution plan, created using EXPLAIN PLAN FOR:

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 1299486493

--------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                           | Name                   | Rows  | Bytes |TempSpc| Cost (%CPU)| Time     | Pstart| Pstop |
--------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                    |                        |  7947 |  1544K|       | 10839   (1)| 00:02:11 |       |       |
|   1 |  SORT GROUP BY                      |                        |  7947 |  1544K|  3368K| 10839   (1)| 00:02:11 |       |       |
|*  2 |   HASH JOIN                         |                        |  7947 |  1544K|       | 10493   (1)| 00:02:06 |       |       |
|   3 |    TABLE ACCESS FULL                | CM_CACHE_BROKER_DETAIL |  6266 |   189K|       |    29   (0)| 00:00:01 |       |       |
|   4 |    TABLE ACCESS BY LOCAL INDEX ROWID| CM_ENUM_TAG            |    41 |  1025 |       |  4970   (1)| 00:01:00 |       |       |
|   5 |     NESTED LOOPS                    |                        |  4796 |   786K|       | 10463   (1)| 00:02:06 |       |       |
|*  6 |      HASH JOIN                      |                        |   117 | 16731 |       |   978   (1)| 00:00:12 |       |       |
|   7 |       TABLE ACCESS FULL             | CM_CACHE_BROKER        |  3781 |   158K|       |    15   (0)| 00:00:01 |       |       |
|   8 |       NESTED LOOPS                  |                        | 74085 |  7234K|       |   962   (1)| 00:00:12 |       |       |
|   9 |        TABLE ACCESS BY INDEX ROWID  | REM_TAG_LIST           |     1 |    43 |       |     1   (0)| 00:00:01 |       |       |
|* 10 |         INDEX UNIQUE SCAN           | AK1_REM_TAG_LIST_CODE  |     1 |       |       |     0   (0)| 00:00:01 |       |       |
|  11 |        TABLE ACCESS BY INDEX ROWID  | REM_TAG_VALUE          | 74085 |  4123K|       |   961   (1)| 00:00:12 |       |       |
|* 12 |         INDEX RANGE SCAN            | REM_TAG_VALUE_IDX1     | 74085 |       |       |   115   (1)| 00:00:02 |       |       |
|  13 |      PARTITION HASH ALL             |                        |  4120 |       |       |    32   (0)| 00:00:01 |     1 |    16 |
|* 14 |       INDEX RANGE SCAN              | IDX5_ENUM_TAG          |  4120 |       |       |    32   (0)| 00:00:01 |     1 |    16 |
--------------------------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("A"."BROKER_ID"="D"."BROKER_ID")
   6 - access("B"."TAG_VALUE"=SYS_OP_C2C("A"."PARENT_BROKER_CODE"))
  10 - access("D"."TAG_LIST_CODE"=U'FCBrokerCode')
  12 - access("D"."TAG_LIST_ID"="B"."TAG_LIST_ID")
  14 - access("B"."TAG_VALUE_ID"="C"."TAG_VALUE_ID")

So, what is unusual about the execution plan?  Look closely at the Predicate Information section.  The “D” alias for ID 2 refers to a different table than the “D” alias for ID 12.  It might have been slightly more interesting if transitive closure changed the predicate for ID 12 to the following, where the “D” aliases on each side of the equal sign referred to different tables (I wonder if this would cause wrong results):

access("D"."TAG_LIST_ID"="D"."TAG_LIST_ID")

OK, but that is not the interesting portion of the Predicate Information section of the execution plan.  Notice that the predicate for ID 6 shows “=SYS_OP_C2C(“A”.”PARENT_BROKER_CODE”))“.  Just what does that SYS_OP_C2C mean?  A web search found two articles describing this function:

Implicit Character Set to Character Set References:
http://jonathanlewis.wordpress.com/2007/07/29/nls/
http://joze-senegacnik.blogspot.com/2009/12/what-is-purpose-of-sysopc2c-internal.html

But, we are not done yet.  Notice that the predicate for ID 10 shows “=U’FCBrokerCode’“.  That “U” character appears to be in an unusual location.  user503699 in the OTN thread provided a test case that triggered an execution plan with a “U” character in a similar position in the access predicates.  The cause?  A column in a table was defined as a NVARCHAR2 datatype, and the WHERE clause of a query specified that the column value must be equal to ‘A’.

Here is a demonstration of what might be happening, using an example similar to what user503699 posted in the OTN thread:

CREATE TABLE T1 (
  C1 VARCHAR2(100),
  C2 NVARCHAR2(100));

INSERT INTO
  T1
SELECT
  'A'||ROWNUM,
  'A'||ROWNUM
FROM
  DUAL
CONNECT BY
  LEVEL<=100000;

COMMIT; 

The above created a table with 100,000 rows with a VARCHAR2 and a NVARCHAR2 column.  Next, we will query the table and display the execution plan:

SELECT
  *
FROM
  T1
WHERE
  C2='A100000';

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'TYPICAL'));

SQL_ID  0j7y39qb11zk3, child number 0
-------------------------------------
SELECT   * FROM   T1 WHERE   C2='A100000'

Plan hash value: 3617692013

--------------------------------------------------------------------------
| Id  | Operation         | Name | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |      |       |       |   103 (100)|          |
|*  1 |  TABLE ACCESS FULL| T1   |     4 |   616 |   103   (1)| 00:00:02 |
--------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter("C2"=U'A100000')

Note
-----
   - dynamic sampling used for this statement

In the above, notice the oddly placed “U”, just like we saw in the OP’s OTN post – this happened when a passed in string was converted for comparison with the NVARCHAR2 column.  Now, a second test:

SELECT
  *
FROM
  T1
WHERE
  C2='A100000'
  AND C1=C2;

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'TYPICAL'));

SQL_ID  6anxauy8vv87b, child number 0
-------------------------------------
SELECT   * FROM   T1 WHERE   C2='A100000'   AND C1=C2

Plan hash value: 3617692013

--------------------------------------------------------------------------
| Id  | Operation         | Name | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |      |       |       |   103 (100)|          |
|*  1 |  TABLE ACCESS FULL| T1   |     9 |  1386 |   103   (1)| 00:00:02 |
--------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter(("C2"=U'A100000' AND SYS_OP_C2C("C1")=U'A100000'))

Note
-----
   - dynamic sampling used for this statement

OK, that ended up a little different than what was expected.  Notice, through the magic of transitive closure on Oracle 11.1.0.7, the AND C1=C2 join condition was removed and replaced with what might be a less efficient predicate, but shows the seemingly unnecessary use of the SYS_OP_C2C function:

  AND SYS_OP_C2C("C1")=U'A100000'

Back to the original problem.  So, what is the cause of the performance problems for the query posted by the OP?  No one yet suggested that the OP should immediately re-execute the query with the following hint to see if the hint helps the query complete faster: 

  /*+ OPT_PARAM('FAST','TRUE') */

Maybe there is a more logical path to fixing the performance problem?





Excel – UserForms with Database Access, Called from VBS

7 02 2010

February 7, 2010

This example shows how to use VBS to call built-in Excel functions, as well as custom developed Excel functions from a VBS file.  Additionally, the VBS code is able to take advantage of an Excel userform that connects to the Oracle database. 

We will start by creating a couple of tables – ideally, we would have more of the application logic and information in each of the database tables, but in this example most of the logic is in Excel.

CREATE TABLE CABINET_BUILDER_WOOD (
  WOOD_TYPE VARCHAR2(30),
  PRIMARY KEY (WOOD_TYPE));

INSERT INTO CABINET_BUILDER_WOOD VALUES ('Birch');
INSERT INTO CABINET_BUILDER_WOOD VALUES ('Cedar');
INSERT INTO CABINET_BUILDER_WOOD VALUES ('Cherry');
INSERT INTO CABINET_BUILDER_WOOD VALUES ('Douglas Fir');
INSERT INTO CABINET_BUILDER_WOOD VALUES ('Ebony');
INSERT INTO CABINET_BUILDER_WOOD VALUES ('Maple');
INSERT INTO CABINET_BUILDER_WOOD VALUES ('Pine');
INSERT INTO CABINET_BUILDER_WOOD VALUES ('Poplar');
INSERT INTO CABINET_BUILDER_WOOD VALUES ('Red Oak');
INSERT INTO CABINET_BUILDER_WOOD VALUES ('Redwood');
INSERT INTO CABINET_BUILDER_WOOD VALUES ('Spruce');
INSERT INTO CABINET_BUILDER_WOOD VALUES ('White Oak');

COMMIT;

CREATE TABLE CABINET_BUILDER_CAB_TYPE (
  CABINET_TYPE VARCHAR2(40),
  PRIMARY KEY (CABINET_TYPE));

INSERT INTO CABINET_BUILDER_CAB_TYPE VALUES ('Base Cabinet Full Depth');
INSERT INTO CABINET_BUILDER_CAB_TYPE VALUES ('Base Cabinet Half Depth');
INSERT INTO CABINET_BUILDER_CAB_TYPE VALUES ('Full Height Base Cabinet');
INSERT INTO CABINET_BUILDER_CAB_TYPE VALUES ('Upper Cabinet');
INSERT INTO CABINET_BUILDER_CAB_TYPE VALUES ('Upper Cabinet Narrow');

COMMIT;

Next, we will start preparing the Excel workbook.  Create a new Excel workbook and save it as C:\ExcelMacroFunctionDemo.xls.  Next, right-click the first worksheet in the workbook and select View Code.  From the Tools menu, select References.  Add a reference to a recent release of the Microsoft ActiveX Data Objects Library, and Microsoft Windows Common Controls 6.0 (hopefully, that version is available on your computer).

From the Tools menu, select Additional Controls.  Place a check next to one of the Microsoft TreeView Controls and then click the OK button.

Next, from the Insert menu, select Module – this is where we will need to add the code so that it may be accessed by the VBS script.  Module1 should appear in the tree structure at the left (officially called the Project Explorer).  Add the following code into the Module1 module (this example is adapted from one that I showed in a presentation to an ERP user’s group, so the contents of some of the functions may seem to be a bit odd):

Option Explicit

'Constants for registry access
Private Const ERROR_SUCCESS = 0&
Private Const SYNCHRONIZE = &H100000
Private Const READ_CONTROL = &H20000
Private Const STANDARD_RIGHTS_ALL = &H1F0000
Private Const STANDARD_RIGHTS_READ = (READ_CONTROL)
Private Const STANDARD_RIGHTS_WRITE = (READ_CONTROL)
Private Const KEY_QUERY_VALUE = &H1
Private Const KEY_SET_VALUE = &H2
Private Const KEY_CREATE_LINK = &H20
Private Const KEY_CREATE_SUB_KEY = &H4
Private Const KEY_ENUMERATE_SUB_KEYS = &H8
Private Const KEY_NOTIFY = &H10
Private Const KEY_READ = ((STANDARD_RIGHTS_READ Or KEY_QUERY_VALUE Or KEY_ENUMERATE_SUB_KEYS Or KEY_NOTIFY) And (Not SYNCHRONIZE))
Private Const KEY_ALL_ACCESS = ((STANDARD_RIGHTS_ALL Or KEY_QUERY_VALUE Or KEY_SET_VALUE Or KEY_CREATE_SUB_KEY Or KEY_ENUMERATE_SUB_KEYS Or KEY_NOTIFY Or KEY_CREATE_LINK) And (Not SYNCHRONIZE))
Private Const KEY_EXECUTE = ((KEY_READ) And (Not SYNCHRONIZE))
Private Const KEY_WRITE = ((STANDARD_RIGHTS_WRITE Or KEY_SET_VALUE Or KEY_CREATE_SUB_KEY) And (Not SYNCHRONIZE))

'For FindWindow
Private Const GW_HWNDFIRST = 0
Private Const GW_HWNDNEXT = 2
Private Const SW_SHOW = 5
Private Const SW_RESTORE = 9

'Type declaration for Zebra label printing
Public Type DOC_INFO_1
    pDocName As String
    pOutputFile As String
    pDatatype As String
End Type

'Registry API functions
Private Declare Function RegCloseKey Lib "advapi32.dll" (ByVal hKey As Long) As Long
Private Declare Function RegCreateKey Lib "advapi32.dll" Alias "RegCreateKeyA" (ByVal hKey As Long, ByVal lpSubKey As String, phkResult As Long) As Long
Private Declare Function RegOpenKeyEx Lib "advapi32.dll" Alias "RegOpenKeyExA" (ByVal hKey As Long, ByVal lpSubKey As String, ByVal ulOptions As Long, ByVal samDesired As Long, phkResult As Long) As Long
Private Declare Function RegQueryValueEx Lib "advapi32.dll" Alias "RegQueryValueExA" (ByVal hKey As Long, ByVal lpValueName As String, ByVal lpReserved As Long, lpType As Long, lpData As Any, lpcbData As Long) As Long
Private Declare Function RegSetValueEx Lib "advapi32.dll" Alias "RegSetValueExA" (ByVal hKey As Long, ByVal lpValueName As String, ByVal Reserved As Long, ByVal dwType As Long, lpData As Any, ByVal cbData As Long) As Long         ' Note that if you declare the lpData parameter as String, you must pass it By Value.

'INI API functions
Public Declare Function GetPrivateProfileString Lib "kernel32" Alias "GetPrivateProfileStringA" (ByVal lpApplicationName As String, ByVal lpKeyName As Any, ByVal lpDefault As String, ByVal lpReturnedString As String, ByVal nSize As Long, ByVal lpFileName As String) As Long
Public Declare Function WritePrivateProfileString Lib "kernel32" Alias "WritePrivateProfileStringA" (ByVal lpApplicationName As String, ByVal lpKeyName As Any, ByVal lpString As Any, ByVal lpFileName As String) As Long

'Zebra Printing API functions
Public Declare Function ClosePrinter Lib "winspool.drv" (ByVal hPrinter As Long) As Long
Public Declare Function EndDocPrinter Lib "winspool.drv" (ByVal hPrinter As Long) As Long
Public Declare Function EndPagePrinter Lib "winspool.drv" (ByVal hPrinter As Long) As Long
Public Declare Function OpenPrinter Lib "winspool.drv" Alias "OpenPrinterA" (ByVal pPrinterName As String, phPrinter As Long, ByVal pDefault As Long) As Long
Public Declare Function StartDocPrinter Lib "winspool.drv" Alias "StartDocPrinterA" (ByVal hPrinter As Long, ByVal Level As Long, pDocInfo As DOC_INFO_1) As Long
Public Declare Function StartPagePrinter Lib "winspool.drv" (ByVal hPrinter As Long) As Long
Public Declare Function WritePrinter Lib "winspool.drv" (ByVal hPrinter As Long, pBuf As Any, ByVal cdBuf As Long, pcWritten As Long) As Long

'For Find Window and bring to top
Private Declare Function AttachThreadInput Lib "user32" (ByVal idAttach As Long, ByVal idAttachTo As Long, ByVal fAttach As Long) As Long
Private Declare Function GetForegroundWindow Lib "user32" () As Long
Private Declare Function GetWindow Lib "user32" (ByVal hWnd As Long, ByVal wCmd As Long) As Long
Private Declare Function GetWindowText Lib "user32" Alias "GetWindowTextA" (ByVal hWnd As Long, ByVal lpString As String, ByVal cch As Long) As Long
Private Declare Function GetWindowTextLength Lib "user32" Alias "GetWindowTextLengthA" (ByVal hWnd As Long) As Long
Private Declare Function GetWindowThreadProcessId Lib "user32" (ByVal hWnd As Long, lpdwProcessId As Long) As Long
Private Declare Function IsIconic Lib "user32" (ByVal hWnd As Long) As Long
Private Declare Function SetForegroundWindow Lib "user32" (ByVal hWnd As Long) As Long
Private Declare Function ShowWindow Lib "user32" (ByVal hWnd As Long, ByVal nCmdShow As Long) As Long

'Used by the ShowWindowAfterDelay sub
Dim strFindWindowTitle As String
Dim intFindExitExcel As String

Public Function CalculateCombinations(lngNumberElements As Long, lngNumberPositions) As Double
    'Calculate the number of possible arrangements where the order does not matter of the number of elements into the number of positions
    CalculateCombinations = Application.WorksheetFunction.Combin(lngNumberElements, lngNumberPositions)
End Function

Public Function CalculateInterestPayment(dblInterestRate As Single, lngPaymentsPerYear As Long, lngNumPayments As Long, sglCurrentValue As Single) As Single
    'Calculates the interest payments on a given principal
    CalculateInterestPayment = Abs(Application.WorksheetFunction.Pmt(dblInterestRate / lngPaymentsPerYear, lngNumPayments, sglCurrentValue))
End Function

Public Function CalculatePermutations(lngNumberElements As Long, lngNumberPositions) As Double
    'Calculate the number of possible arrangements where the order matters of the number of elements into the number of positions
    CalculatePermutations = Application.WorksheetFunction.Permut(lngNumberElements, lngNumberPositions)
End Function

Public Function EnvironmentVariable(strIn As String) As String
    'Returns the environment variable set on the computer
        'EnvironmentVariable("windir")       'Windows folder
        'EnvironmentVariable("temp")         'Temp folder
        'EnvironmentVariable("username")     'Username
        'EnvironmentVariable("computername") 'Computer name
    EnvironmentVariable = Environ(strIn)
End Function

Private Function ForceForegroundWindow(ByVal hWnd As Long) As Long
    Dim lngThreadID1 As Long
    Dim lngThreadID2 As Long
    Dim lngResult As Long

    If hWnd = GetForegroundWindow() Then
        ForceForegroundWindow = True
    Else
        lngThreadID1 = GetWindowThreadProcessId(GetForegroundWindow, ByVal 0&)
        lngThreadID2 = GetWindowThreadProcessId(hWnd, ByVal 0&)

        If lngThreadID1 <> lngThreadID2 Then
            Call AttachThreadInput(lngThreadID1, lngThreadID2, True)
            lngResult = SetForegroundWindow(hWnd)
            Call AttachThreadInput(lngThreadID1, lngThreadID2, False)
        Else
            lngResult = SetForegroundWindow(hWnd)
        End If

        If IsIconic(hWnd) Then
            Call ShowWindow(hWnd, SW_RESTORE)
        Else
            Call ShowWindow(hWnd, SW_SHOW)
        End If

        ForceForegroundWindow = lngResult
    End If
End Function

Public Function RegistryGetEntry(strSubKeys As String, strValName As String) As String
    'Reads a string value from the HKEY_CURRENT_USER section of the registry
    Const lngType = 1&
    Const lngKey = &H80000001 'HKEY_CURRENT_USER

    Dim lngResult As Long
    Dim lngHandle As Long
    Dim lngcbData As Long
    Dim strRet As String

    On Error Resume Next

    lngResult = RegOpenKeyEx(lngKey, strSubKeys, 0&, KEY_READ, lngHandle)

    If lngResult <> ERROR_SUCCESS Then
        RegistryGetEntry = "!!!KEY DOES NOT EXIST" & vbTab & Format(lngResult)
        Exit Function
    End If

    strRet = String(300, Chr(0))
    lngcbData = Len(strRet)
    lngResult = RegQueryValueEx(lngHandle, strValName, 0&, lngType, ByVal strRet, lngcbData)

    'See if the value to be returned is longer than the number of character positions in the passed in string
    If lngcbData > 300 Then
        'String not long enough, try again
        strRet = String(lngcbData, Chr(0))
        lngResult = RegQueryValueEx(lngHandle, strValName, 0&, lngType, ByVal strRet, lngcbData)
    End If

    If lngResult <> ERROR_SUCCESS Then
        RegistryGetEntry = "!!!VALUE DOES NOT EXIST" & vbTab & Format(lngResult)
    Else
        RegistryGetEntry = Left(strRet, lngcbData - 1)
    End If

    lngResult = RegCloseKey(lngHandle)
End Function

Public Function RegistrySetEntry(strSubKeys As String, strValName As String, strValue As String) As Long
    Const lngType = 1&
    Const lngKey = &H80000001 'HKEY_CURRENT_USER

    Dim lngResult As Long
    Dim lngHandle As Long
    Dim lngcbData As Long
    Dim strRet As String
    Dim strNewKey As String

    On Error Resume Next

    lngResult = RegCreateKey(lngKey, strSubKeys, lngHandle)

    lngResult = RegSetValueEx(lngHandle, strValName, 0&, lngType, ByVal strValue, Len(strValue))

    If lngResult <> ERROR_SUCCESS Then
        RegistrySetEntry = False
    Else
        RegistrySetEntry = True
    End If

    lngResult = RegCloseKey(lngHandle)
End Function

Public Function ReverseString(strIn As Variant) As Variant
    'Reverses a string value using a simple VBA macro
    Dim i As Integer
    Dim strTemp As String

    For i = Len(strIn) To 1 Step -1
        strTemp = strTemp & Mid(strIn, i, 1)
    Next i

    ReverseString = strTemp
End Function

Public Function RoundNumber(dblIn As Double, intDigits As Integer, intPrintCommas As Integer) As String
    'Switch the value of the variable so that TRUE becomes FALSE and FALSE becomes TRUE
    intPrintCommas = Not intPrintCommas
    'Round the number to the specified number of decimal places
    RoundNumber = Application.WorksheetFunction.Fixed(dblIn, intDigits, intPrintCommas)
End Function

Public Function ShowCabinetBuilder(sglMarkup As Single) As Variant
    Dim i As Integer
    Dim intBOMNodes As Integer
    Dim intBOMCount As Integer
    Dim strMaterialList As String

    frmCabinetBuilder.sglPriceMarkup = sglMarkup
    frmCabinetBuilder.Show

    intBOMNodes = frmCabinetBuilder.tvBillOfMaterial.Nodes.Count
    'Set the initial size of the array to be returned to the number of items in the treeview

    intBOMCount = 0
    If (frmCabinetBuilder.intFormCancelled = False) And (intBOMNodes > 0) Then
        For i = 1 To intBOMNodes
            'Do not return the category headings
            If frmCabinetBuilder.tvBillOfMaterial.Nodes(i).Children = 0 Then
                intBOMCount = intBOMCount + 1
                strMaterialList = strMaterialList & frmCabinetBuilder.tvBillOfMaterial.Nodes(i).Text & vbTab
            End If
        Next i
    Else

    End If

    If strMaterialList <> "" Then
        strMaterialList = Left(strMaterialList, Len(strMaterialList) - 1)
    End If

    ShowCabinetBuilder = strMaterialList

    'Remove the form from memory
    Unload frmCabinetBuilder
End Function

Public Sub ShowWindowWithDelay(strWindowTitle As String, Optional intDelaySeconds As Integer = 1, Optional intExitExcel As Integer = False)
    'Used to display a window that is opened within a Visual macro - usually behind the Visual module

    DoEvents
    'Set a couple module level variables that will be used in the ShowWindowAfterDelay sub
    strFindWindowTitle = strWindowTitle
    intFindExitExcel = intExitExcel

    'After the specified number of seconds locate and show the window
    Application.OnTime DateAdd("s", intDelaySeconds, Now), "ShowWindowAfterDelay"
End Sub

Private Sub ShowWindowAfterDelay()
    Dim intLength As Integer 'Length of the window text length
    Dim strListItem As String 'Name of running programs
    Dim lngCurrWnd As Long 'Current window handle
    Dim lngResult As Long 'Return value from the API calls
    Dim intFlag As Integer

    On Error Resume Next

    lngCurrWnd = GetWindow(Application.hWnd, GW_HWNDFIRST)

    'Loop through all of the top-level windows to find the one of interest
    Do While lngCurrWnd <> 0
        intLength = GetWindowTextLength(lngCurrWnd)
        strListItem = Space$(intLength + 1)
        intLength = GetWindowText(lngCurrWnd, strListItem, intLength + 1)
        If intLength > 0 Then
            If InStr(UCase(strListItem), UCase(strFindWindowTitle)) > 0 Then
                lngResult = ForceForegroundWindow(lngCurrWnd)
                DoEvents

                intFlag = True
                Exit Do
            End If
        End If

        lngCurrWnd = GetWindow(lngCurrWnd, GW_HWNDNEXT)

        DoEvents
    Loop

    strFindWindowTitle = ""

    If intFindExitExcel = True Then
        ActiveWorkbook.Saved = True
        Application.Quit
    End If
End Sub

Public Function ToHexadecimal(dblIn As Double) As String
    'Will not work in Excel 2003
    'Changes the number passed in to hexadecimal using a built-in function, could use VB's HEX function
    ToHexadecimal = Application.WorksheetFunction.Dec2Hex(dblIn)
End Function

Public Function ToRoman(dblIn As Double) As String
    'Changes the number passed in to Roman numerals using a built-in function
    ToRoman = Application.WorksheetFunction.Roman(dblIn, 0)
End Function

Public Function VisualINIGet(strSection As String, strName As String, Optional strINIFile As String = "Visual.ini") As String
    Dim lngResult As Long
    Dim lngRetSize As Long
    Dim strLocalVisualDirectory As String
    Dim strFilename As String
    Dim strRet As String

    strLocalVisualDirectory = RegistryGetEntry("Software\Infor Global Solutions\VISUAL Manufacturing\Configuration", "Local Directory")

    If Left(strLocalVisualDirectory, 3) = "!!!" Then
        'Registry access failed, try again with Lilly Software
        strLocalVisualDirectory = RegistryGetEntry("Software\Lilly Software\VISUAL Manufacturing\Configuration", "Local Directory")
    End If

    If (Left(strLocalVisualDirectory, 3) <> "!!!") And (strLocalVisualDirectory <> "") Then
        'Make certain that the path end in a \
        If Right(strLocalVisualDirectory, 1) <> "\" Then
            strLocalVisualDirectory = strLocalVisualDirectory & "\"
        End If

        'Make certain that the ini file ends with .INI
        If Len(strINIFile) > 4 Then
            If Right(UCase(strINIFile), 4) <> ".INI" Then
                strINIFile = strINIFile & ".ini"
            End If
        Else
            strINIFile = strINIFile & ".ini"
        End If

        strFilename = strLocalVisualDirectory & strINIFile

        lngRetSize = 255
        strRet = String(lngRetSize, Chr(0))
        lngResult = GetPrivateProfileString(strSection, strName, "", strRet, lngRetSize, strFilename)

        If lngResult <> 0 Then
            VisualINIGet = Left(strRet, InStr(strRet, Chr(0)) - 1)
        Else
            VisualINIGet = "!!!VALUE DOES NOT EXIST"
        End If
    Else
        'Registry access failed
        VisualINIGet = "!!!LOCATION OF VISUAL.INI NOT KNOWN"
    End If
End Function

Public Function VisualINISet(strSection As String, strName As String, strValue As String, Optional strINIFile As String = "Visual.ini") As Long
    Dim lngResult As Long
    Dim lngRetSize As Long
    Dim strLocalVisualDirectory As String
    Dim strFilename As String
    Dim strRet As String

    strLocalVisualDirectory = RegistryGetEntry("Software\Infor Global Solutions\VISUAL Manufacturing\Configuration", "Local Directory")

    If Left(strLocalVisualDirectory, 3) = "!!!" Then
        'Registry access failed, try again with Lilly Software
        strLocalVisualDirectory = RegistryGetEntry("Software\Lilly Software\VISUAL Manufacturing\Configuration", "Local Directory")
    End If

    If (Left(strLocalVisualDirectory, 3) <> "!!!") And (strLocalVisualDirectory <> "") Then
        'Make certain that the path end in a \
        If Right(strLocalVisualDirectory, 1) <> "\" Then
            strLocalVisualDirectory = strLocalVisualDirectory & "\"
        End If

        'Make certain that the ini file ends with .INI
        If Len(strINIFile) > 4 Then
            If Right(UCase(strINIFile), 4) <> ".INI" Then
                strINIFile = strINIFile & ".ini"
            End If
        Else
            strINIFile = strINIFile & ".ini"
        End If

        strFilename = strLocalVisualDirectory & strINIFile
        lngResult = WritePrivateProfileString(strSection, strName, strValue, strFilename)

        If lngResult <> 0 Then
            VisualINISet = True
        Else
            VisualINISet = False
        End If
    Else
        VisualINISet = False
    End If
End Function

Public Sub ZebraPrintLabel(strPrinter As Variant, strRawText As Variant)
    'Variables for handling printing
    Dim i As Integer
    Dim lngPrinterHandle As Long
    Dim lngResult As Long
    Dim lngWritten As Long
    Dim lngPrinterDocHandle As Long
    Dim bytRawText() As Byte
    Dim MyDocInfo As DOC_INFO_1

    On Error Resume Next

    'In VB6 to see the list of printer device names, enter the following into the Debug window
    'For i = 0 to Printers.Count - 1:Debug.Print Printers(i).DeviceName:Next

    'strPrinter = "\\MYCOMP\ZEBRA"

    'Sample label
    'strRawText = "~SD25^XA" 'Set Darkness, Label start
    'strRawText = strRawText & "^SZ2" 'Enable ZPL2
    'strRawText = strRawText & "^JZ" 'Reprint on error
    'strRawText = strRawText & "^PR8,8,8" 'Print speed 8" per second, 8" per sec slew, 8" per sec backfeed
    'strRawText = strRawText & "^LH10,26" 'Label home position in pixels
    'strRawText = strRawText & "^FO2,14^A0R,20,20^FDMy Company^FS" 'rotated text in font A
    'strRawText = strRawText & "^FO2,480^A0R,20,20^FDSomewhere^FS"
    'strRawText = strRawText & "^FO180,135^B3R,,105,N^FD" & "ABC111" & "^FS"  'Font 3 of 9 barcode
    'strRawText = strRawText & "^FO180,0^GB0,760,3^FS"  'Vertical Line 3 pixels wide
    'strRawText = strRawText & "^FO335,0^GB0,1218,3^FS"  'Vertical Line 3 pixels wide
    'strRawText = strRawText & "^FO550,0^GB0,1218,3^FS"  'Vertical Line 3 pixels wide
    'strRawText = strRawText & "^FO260,760^GB0,452,3^FS"  'Vertical Line 3 pixels wide
    'strRawText = strRawText & "^FO0,760^GB335,0,3^FS"  'Horizontal Line 3 pixels wide
    'strRawText = strRawText & "^XZ"  'End of label indicator

    'Convert the variant data types to strings
    strPrinter = CStr(strPrinter)
    strRawText = CStr(strRawText)

    'Terminate the string with a CRLF combination (may not be needed)
    If Right(strRawText, 2) <> vbCrLf Then
        strRawText = strRawText & vbCrLf
    End If

    'Convert the strRawText string to a byte stream
    ReDim bytRawText(1 To Len(strRawText))
    For i = 1 To Len(strRawText)
        bytRawText(i) = Asc(Mid(strRawText, i, 1))
    Next i

    'Create a connection to the printer, returns a handle to the printer
    lngResult = OpenPrinter(strPrinter, lngPrinterHandle, 0)

    If lngPrinterHandle = 0 Then
        MsgBox "Could Not Open Printer"
        Exit Sub
    End If

    'Fill in the document header structure
    MyDocInfo.pDocName = "Zebra Label from Excel"
    MyDocInfo.pOutputFile = vbNullString
    MyDocInfo.pDatatype = "RAW"
    lngPrinterDocHandle = StartDocPrinter(lngPrinterHandle, 1, MyDocInfo)

    If lngPrinterDocHandle = 0 Then
        MsgBox "Could Not Start the Document"
        lngResult = ClosePrinter(lngPrinterHandle)
        Exit Sub
    End If

    'Prepare to start the first page
    Call StartPagePrinter(lngPrinterHandle)

    'Write out the contents of the first page
    lngResult = WritePrinter(lngPrinterHandle, bytRawText(1), Len(strRawText), lngWritten)
    If lngResult = 0 Then
        MsgBox "Could Not Write to the Page"
        lngResult = ClosePrinter(lngPrinterHandle)
        Exit Sub
    End If

    'End the first page
    lngResult = EndPagePrinter(lngPrinterHandle)

    'End the document
    lngResult = EndDocPrinter(lngPrinterHandle)

    'Close the connection to the printet
    lngResult = ClosePrinter(lngPrinterHandle)
End Sub

OK, now that the easy part is done, we need to Create the UserForm that will be accessed from the VBS script.  From the Insert menu, select UserForm.  Change the name of the form to frmCabinetBuilder.  Draw a Treeview type control on the userform (the treeview is hilighted in the below screen capture) and name the treeview as tvBillOfMaterial.  Draw two ListBox controls on the userform and name them lstWoodType and lstCabinetType (shown below near the upper left of the userform).  Create three CommandButton contols and name them cmdCreateSalesOrder, cmdCreateWorkOrder, and cmdExit (shown near the bottom of the userform).  Create two TextBox controls and name them txtManufactureCost and txtSalesPrice (shown near the top right of the userform).  Create Label controls on the userform above each of the other controls, and set their Caption property to the text that should appear inside the label control (Wood Type, Cabinet Type, etc.).

Next, we need to add code to the userform so that the controls know what to do.  Double-click the background of the userform, delete any code shown, and add the following code:

Option Explicit 'Forces all variables to be declared

Public intFormCancelled As Integer
Public sglPriceMarkup As Single

Dim dbDatabase As New ADODB.Connection
Dim strDatabase As String
Dim strUserName As String
Dim strPassword As String

Private Function ConnectDatabase() As Integer
    Dim intResult As Integer

    On Error Resume Next

    If dbDatabase.State <> 1 Then
        'Connection to the database if closed, specify the database name, a username, and password
        strDatabase = "MyDB"
        strUserName = "MyUser"
        strPassword = "MyPassword"

        'Connect to the database
        'Oracle connection string
        dbDatabase.ConnectionString = "Provider=OraOLEDB.Oracle;Data Source=" & strDatabase & ";User ID=" & strUserName & ";Password=" & strPassword & ";ChunkSize=1000;FetchSize=100;"

        dbDatabase.ConnectionTimeout = 40
        dbDatabase.CursorLocation = adUseClient
        dbDatabase.Open

        If (dbDatabase.State <> 1) Or (Err <> 0) Then
            intResult = MsgBox("Could not connect to the database.  Check your user name and password." & vbCrLf & Error(Err), 16, "Excel Demo")

            ConnectDatabase = False
        Else
            ConnectDatabase = True
        End If
    Else
        ConnectDatabase = True
    End If
End Function

Private Sub Calculate()
    Const tvwChild = 4

    Dim i As Integer
    Dim sglPrice As Single
    Dim sglBasePrice As Single
    Dim sglWoodPriceMultiplier As Single

    tvBillOfMaterial.Nodes.Clear

    If (lstWoodType.ListIndex >= 0) And (lstCabinetType.ListIndex >= 0) Then
        Select Case lstCabinetType.List(lstCabinetType.ListIndex)
            Case "Base Cabinet Full Depth"
                tvBillOfMaterial.Nodes.Add , , "Door", "Door"
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DStile1", "Stile 1" & "   " & "3/4 X 2 X 30" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DStile2", "Stile 2" & "   " & "3/4 X 2 X 30" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DRail1", "Rail 1" & "   " & "3/4 X 2 X 21 3/4" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DRail2", "Rail 2" & "   " & "3/4 X 2 X 21 3/4" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DPanel", "Panel" & "   " & "5/8 X 21 3/4 X 27 3/4" & "   " & lstWoodType.List(lstWoodType.ListIndex)

                tvBillOfMaterial.Nodes.Add , , "Case", "Case"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CStile1", "Stile 1" & "   " & "3/4 X 2 X 31" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CStile2", "Stile 2" & "   " & "3/4 X 2 X 31" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CRail1", "Rail 1" & "   " & "3/4 X 2 X 24" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CRail2", "Rail 2" & "   " & "3/4 X 2 X 24" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CKicker", "Kicker" & "   " & "5/8 X 21 3/4 X 27 3/4" & "   " & "Particle Board"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CSide1", "Side 1" & "   " & "3/4 X 24 X 35" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CSide2", "Side 2" & "   " & "3/4 X 24 X 35" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CBack", "Back" & "   " & "3/4 X 22 1/2 X 35" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CTop", "Top" & "   " & "3/4 X 22 1/2 X 23 1/4" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CBottom", "Bottom" & "   " & "3/4 X 22 1/2 X 23 1/4" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"

                sglBasePrice = 150
            Case "Base Cabinet Half Depth"
                tvBillOfMaterial.Nodes.Add , , "Door", "Door"
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DStile1", "Stile 1" & "   " & "3/4 X 2 X 30" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DStile2", "Stile 2" & "   " & "3/4 X 2 X 30" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DRail1", "Rail 1" & "   " & "3/4 X 2 X 21 3/4" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DRail2", "Rail 2" & "   " & "3/4 X 2 X 21 3/4" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DPanel", "Panel" & "   " & "5/8 X 21 3/4 X 27 3/4" & "   " & lstWoodType.List(lstWoodType.ListIndex)

                tvBillOfMaterial.Nodes.Add , , "Case", "Case"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CStile1", "Stile 1" & "   " & "3/4 X 2 X 31" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CStile2", "Stile 2" & "   " & "3/4 X 2 X 31" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CRail1", "Rail 1" & "   " & "3/4 X 2 X 24" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CRail2", "Rail 2" & "   " & "3/4 X 2 X 24" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CKicker", "Kicker" & "   " & "5/8 X 21 3/4 X 27 3/4" & "   " & "Particle Board"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CSide1", "Side 1" & "   " & "3/4 X 12 X 35" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CSide2", "Side 2" & "   " & "3/4 X 12 X 35" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CBack", "Back" & "   " & "3/4 X 22 1/2 X 35" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CTop", "Top" & "   " & "3/4 X 22 1/2 X 11 1/4" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CBottom", "Bottom" & "   " & "3/4 X 22 1/2 X 11 1/4" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"

                sglBasePrice = 120
            Case "Full Height Base Cabinet"
                tvBillOfMaterial.Nodes.Add , , "Door", "Door"
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DStile1", "Stile 1" & "   " & "3/4 X 2 X 67" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DStile2", "Stile 2" & "   " & "3/4 X 2 X 67" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DRail1", "Rail 1" & "   " & "3/4 X 2 X 21 3/4" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DRail2", "Rail 2" & "   " & "3/4 X 2 X 21 3/4" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DPanel", "Panel" & "   " & "5/8 X 21 3/4 X 63 1/4" & "   " & lstWoodType.List(lstWoodType.ListIndex)

                tvBillOfMaterial.Nodes.Add , , "Case", "Case"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CStile1", "Stile 1" & "   " & "3/4 X 2 X 72" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CStile2", "Stile 2" & "   " & "3/4 X 2 X 72" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CRail1", "Rail 1" & "   " & "3/4 X 2 X 24" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CRail2", "Rail 2" & "   " & "3/4 X 2 X 24" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CKicker", "Kicker" & "   " & "5/8 X 21 3/4 X 27 3/4" & "   " & "Particle Board"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CSide1", "Side 1" & "   " & "3/4 X 24 X 72" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CSide2", "Side 2" & "   " & "3/4 X 24 X 72" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CBack", "Back" & "   " & "3/4 X 22 1/2 X 72" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CTop", "Top" & "   " & "3/4 X 22 1/2 X 23 1/4" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CBottom", "Bottom" & "   " & "3/4 X 22 1/2 X 23 1/4" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"

                sglBasePrice = 250
            Case "Upper Cabinet"
                tvBillOfMaterial.Nodes.Add , , "Door", "Door"
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DStile1", "Stile 1" & "   " & "3/4 X 2 X 9 1/4" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DStile2", "Stile 2" & "   " & "3/4 X 2 X 9 1/4" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DRail1", "Rail 1" & "   " & "3/4 X 2 X 21 3/4" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DRail2", "Rail 2" & "   " & "3/4 X 2 X 21 3/4" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DPanel", "Panel" & "   " & "5/8 X 21 3/4 X 9 1/4" & "   " & lstWoodType.List(lstWoodType.ListIndex)

                tvBillOfMaterial.Nodes.Add , , "Case", "Case"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CStile1", "Stile 1" & "   " & "3/4 X 2 X 12" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CStile2", "Stile 2" & "   " & "3/4 X 2 X 12" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CRail1", "Rail 1" & "   " & "3/4 X 2 X 24" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CRail2", "Rail 2" & "   " & "3/4 X 2 X 24" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CSide1", "Side 1" & "   " & "3/4 X 11 1/4 X 12" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CSide2", "Side 2" & "   " & "3/4 X 11 1/4 X 12" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CBack", "Back" & "   " & "3/4 X 22 1/2 X 12" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CTop", "Top" & "   " & "3/4 X 22 1/2 X 11 1/4" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CBottom", "Bottom" & "   " & "3/4 X 22 1/2 X 11 1/4" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"

                sglBasePrice = 100
            Case "Upper Cabinet Narrow"
                tvBillOfMaterial.Nodes.Add , , "Door", "Door"
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DStile1", "Stile 1" & "   " & "3/4 X 2 X 9 1/4" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DStile2", "Stile 2" & "   " & "3/4 X 2 X 9 1/4" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DRail1", "Rail 1" & "   " & "3/4 X 2 X 9 3/4" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DRail2", "Rail 2" & "   " & "3/4 X 2 X 9 3/4" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Door", tvwChild, "DPanel", "Panel" & "   " & "5/8 X 9 3/4 X 9 1/4" & "   " & lstWoodType.List(lstWoodType.ListIndex)

                tvBillOfMaterial.Nodes.Add , , "Case", "Case"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CStile1", "Stile 1" & "   " & "3/4 X 2 X 12" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CStile2", "Stile 2" & "   " & "3/4 X 2 X 12" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CRail1", "Rail 1" & "   " & "3/4 X 2 X 12" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CRail2", "Rail 2" & "   " & "3/4 X 2 X 12" & "   " & lstWoodType.List(lstWoodType.ListIndex)
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CSide1", "Side 1" & "   " & "3/4 X 11 1/4 X 12" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CSide2", "Side 2" & "   " & "3/4 X 11 1/4 X 12" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CBack", "Back" & "   " & "3/4 X 10 1/2 X 12" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CTop", "Top" & "   " & "3/4 X 10 1/2 X 11 1/4" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"
                tvBillOfMaterial.Nodes.Add "Case", tvwChild, "CBottom", "Bottom" & "   " & "3/4 X 10 1/2 X 11 1/4" & "   " & lstWoodType.List(lstWoodType.ListIndex) & " Plywood"

                sglBasePrice = 60
        End Select

        Select Case lstWoodType.List(lstWoodType.ListIndex)
            Case "Birch"
                sglWoodPriceMultiplier = 3.2
            Case "Cedar"
                sglWoodPriceMultiplier = 2.4
            Case "Cherry"
                sglWoodPriceMultiplier = 6
            Case "Douglas Fir"
                sglWoodPriceMultiplier = 2.8
            Case "Ebony"
                sglWoodPriceMultiplier = 12
            Case "Maple"
                sglWoodPriceMultiplier = 3.3
            Case "Pine"
                sglWoodPriceMultiplier = 1.5
            Case "Poplar"
                sglWoodPriceMultiplier = 1.3
            Case "Red Oak"
                sglWoodPriceMultiplier = 2.5
            Case "Redwood"
                sglWoodPriceMultiplier = 6
            Case "Spruce"
                sglWoodPriceMultiplier = 1
            Case "White Oak"
                sglWoodPriceMultiplier = 3
        End Select

        If sglPriceMarkup = 0 Then
            sglPriceMarkup = 0.3
        End If

        sglPrice = Round((sglBasePrice * sglWoodPriceMultiplier) * (1 + sglPriceMarkup), 2)

        txtSalesPrice = Format(sglPrice, "$0.00")
        txtManufactureCost = Format(Round((sglBasePrice * sglWoodPriceMultiplier), 2), "$0.00")
    End If

    For i = 1 To tvBillOfMaterial.Nodes.Count
        'Force all of the nodes to appear expanded
        tvBillOfMaterial.Nodes(i).Expanded = True
    Next i
    If tvBillOfMaterial.Nodes.Count > 0 Then
        tvBillOfMaterial.Nodes(1).Selected = True
    End If
End Sub

Private Sub cmdExit_Click()
    'Set the variable to indicate that the user did not force the window to close
    intFormCancelled = False

    'Make the form disappear
    Me.Hide
End Sub

Private Sub lstCabinetType_Click()
    Calculate
End Sub

Private Sub lstWoodType_Click()
    Calculate
End Sub

Private Sub UserForm_Initialize()
    Dim lngResult As Long
    Dim strSQL As String
    Dim snpData As ADODB.Recordset

    On Error Resume Next

    Set snpData = New ADODB.Recordset

    lngResult = ConnectDatabase

    If lngResult = True Then
        strSQL = "SELECT" & vbCrLf
        strSQL = strSQL & "  WOOD_TYPE" & vbCrLf
        strSQL = strSQL & "FROM" & vbCrLf
        strSQL = strSQL & "  CABINET_BUILDER_WOOD" & vbCrLf
        strSQL = strSQL & "ORDER BY" & vbCrLf
        strSQL = strSQL & "  WOOD_TYPE"
        snpData.Open strSQL, dbDatabase

        If snpData.State = 1 Then
            Do While Not snpData.EOF
                lstWoodType.AddItem snpData("wood_type")

                snpData.MoveNext
            Loop

            snpData.Close
        End If

        strSQL = "SELECT" & vbCrLf
        strSQL = strSQL & "  CABINET_TYPE" & vbCrLf
        strSQL = strSQL & "FROM" & vbCrLf
        strSQL = strSQL & "  CABINET_BUILDER_CAB_TYPE" & vbCrLf
        strSQL = strSQL & "ORDER BY" & vbCrLf
        strSQL = strSQL & "  CABINET_TYPE"
        snpData.Open strSQL, dbDatabase

        If snpData.State = 1 Then
            Do While Not snpData.EOF
                lstCabinetType.AddItem snpData("cabinet_type")

                snpData.MoveNext
            Loop

            snpData.Close
        End If
    End If

    Set snpData = Nothing
    'lstWoodType.List = Array("Birch", "Cedar", "Cherry", "Douglas Fir", "Ebony", "Maple", "Pine", "Poplar", "Red Oak", "Redwood", "Spruce", "White Oak")
    'lstCabinetType.List = Array("Base Cabinet Full Depth", "Base Cabinet Half Depth", "Full Height Base Cabinet", "Upper Cabinet", "Upper Cabinet Narrow")
End Sub

Private Sub UserForm_QueryClose(Cancel As Integer, CloseMode As Integer)
    'Prevent the form from being unloaded
    Cancel = True

    'Set the variable to indicate that the user closed the window
    intFormCancelled = True

    'Make the form disappear
    Me.Hide
End Sub

To keep matters simple, I elected to not pull up the costs for the various cabinets, the price premiums for different wood types, or the bill of material from the database.  If all was successful, at this point you should be able to type the following into the Immediate Window to show the userform:

a = ShowCabinetBuilder( 1 )

Almost done, now we just need the VBS script that will interact with the Excel workbook.  Use Notepad to create a new text file named “C:\ExcelMacroFunctionsDemo.vbs” and add the following code:

Dim i
Dim objExcel
Dim objShell
Dim sglResult
Dim strResult
Dim strBOM
Dim strMaterial
Dim strOut
Dim strOpenDate
Dim strVendorID

Set objExcel = CreateObject("Excel.Application")

strOpenDate = cDate("January 7, 2010")
strVendorID = "MyCompanyHere"

strOut = ""
With objExcel
    'Open the Excel file containing the macro functions
    .Workbooks.Open "C:\ExcelMacroFunctionDemo.xls"

    'Excute a standard macro located in mdlGlobal, pass in the vendor ID from Visual
    strResult = .Application.Run("ReverseString", strVendorID)
    strOut = strOut & "Execute a Custom Excel Macro:" & vbCrLf
    strOut = strOut & " The vendor ID spelled backward is " & strResult & vbCrLf

    'Excute a macro located in mdlGlobal that calls an internal Excel function
    strResult = .Application.Run("ToRoman", Year(strOpenDate))
    strOut = strOut & vbCrLf & "Execute a Custom Excel Macro - Calls Int. Excel Func:" & vbCrLf
    strOut = strOut & " The open date year in Roman numerals is " & strResult & vbCrLf

    'Excute a macro located in mdlGlobal that calls an internal Excel function, function not available on Excel 2003
    'strResult = .Application.Run("ToHexadecimal", Year(strOpenDate))
    'strOut = strOut & "The open date year in Hexadecimal is " & strResult & vbCrLf

    'Excute a macro located in mdlGlobal that calls an internal Excel function
    strResult = .Application.Run("CalculateCombinations", 5, 3)
    strOut = strOut & " There are " & strResult & " cominations of 5 objects arranged in 3 slots" & vbCrLf
    strResult = .Application.Run("CalculateCombinations", 5, 4)
    strOut = strOut & " There are " & strResult & " cominations of 5 objects arranged in 4 slots" & vbCrLf
    strResult = .Application.Run("CalculatePermutations", 5, 3)
    strOut = strOut & " There are " & strResult & " permutations of 5 objects arranged in 3 slots" & vbCrLf
    strResult = .Application.Run("CalculatePermutations", 5, 4)
    strOut = strOut & " There are " & strResult & " permutations of 5 objects arranged in 4 slots" & vbCrLf

    'Excute a macro located in mdlGlobal that calls an internal Excel function with multiple parameters
    sglResult = .Application.Run("CalculateInterestPayment", 0.07, 12, 4 * 12, 30000)
    strOut = strOut & " A monthly payment on a $30,000 loan at 7% interest is $" & FormatNumber(sglResult, 2) & " for 4 years" & vbCrLf   

    'Directly execute an internal Excel function, function not available on Excel 2003
    'sglResult = .Application.WorksheetFunction.NetworkDays(Date, cDate("12/31/" & cStr(Year(Now))))
    'strOut = strOut & "There are " & cStr(sglResult) & " week days left in the year" & vbCrLf

    'Directly execute an internal Excel function
    strOut = strOut & vbCrLf & "Directly Execute Internal Excel Func:" & vbCrLf
    sglResult = .Application.WorksheetFunction.Average(10,3,4,5,6,100)
    strOut = strOut & " The average of 10,3,4,5,6,100 is " & cStr(sglResult) & vbCrLf
    sglResult = .Application.WorksheetFunction.Product(10,3,4,5,6,100)
    strOut = strOut & " The product of 10,3,4,5,6,100 is " & cStr(sglResult) & vbCrLf
    sglResult = .Application.WorksheetFunction.StDev(10,3,4,5,6,100)
    strOut = strOut & " The standard deviation of 10,3,4,5,6,100 is " & cStr(sglResult) & vbCrLf
    MsgBox strOut, vbInformation, "Excel Macro Functions"

    strOut = ""
    'Excute a macro located in mdlGlobal that retrieves a value from one of Visual's INI files
    strOut = strOut & "Read Values from Visual INIs:" & vbCrLf
    strResult = .Application.Run("VisualINIGet", "PlanningWindow", "ShowUnreleased", "Visual.ini")
    If (Left(Ucase(strResult), 1) = "Y") Or (Left(Ucase(strResult), 1) = "1") Then
        strOut = strOut & " The Material Planning Window will show Unreleased orders" & vbCrLf
    Else
        strOut = strOut & " The Material Planning Window will show Not Unreleased orders" & vbCrLf
    End IF
    strResult = .Application.Run("VisualINIGet", "Work Orders", "table", "vmbrowse.ini")
    strOut = strOut & " WO Browse tables=: " & strResult & vbCrLf
    strResult = .Application.Run("VisualINIGet", "Work Orders", "where", "vmbrowse.ini")
    strOut = strOut & " WO Browse where=: " & strResult & vbCrLf
    strResult = .Application.Run("VisualINIGet", "Work Orders", "decode", "vmbrowse.ini")
    strOut = strOut & " WO Browse columns=: " & strResult & vbCrLf
    MsgBox strOut, vbInformation, "Excel Macro Functions"

    strOut = ""
    'Excute a macro located in mdlGlobal that retrieves values from the registry
    strOut = strOut & "Read Values from Windows Registry:" & vbCrLf
    strResult = .Application.Run("RegistryGetEntry", "Control Panel\Desktop", "Wallpaper")
    strOut = strOut & " Desktop Picture: " & strResult & vbCrlf

    'Excute a macro located in mdlGlobal that retrieves environment variables
    strOut = strOut & vbCrLf & "Read Values from Windows Env Variables:" & vbCrLf
    strResult = .Application.Run("EnvironmentVariable", "username")
    strOut = strOut & " User: " & strResult
    strResult = .Application.Run("EnvironmentVariable", "computername")
    strOut = strOut & " is logged into the computer: " & strResult
    strResult = .Application.Run("EnvironmentVariable", "windir")
    strOut = strOut & " with the Windows folder located in: " & strResult
    strResult = .Application.Run("EnvironmentVariable", "temp")
    strOut = strOut & " and the temp folder is located in: " & strResult
    MsgBox strOut, vbInformation, "Excel Macro Functions"

    'Show an Excel user form by calling a public macro function in the located in mdlGlobal module
    strResult = InputBox("Enter Markup Percent (for example  50) for Cabinet Builder", "Excel Macro Functions")
    If IsNumeric(strResult) Then
        'with the help of custom program, set a 1 second delay, then force the window to the top
        Set objShell = CreateObject("WScript.Shell")
        objShell.Run("C:\BringToTop.exe " & Chr(34) & "Cabinet Builder" & Chr(34) & " 1")

        strBOM = .Application.Run("ShowCabinetBuilder", cSng(strResult) / 100)

        Set objShell = Nothing

        'BOM is tab delimited, split apart
        strMaterial = Split(cStr(strBOM), vbTab)

        strOut = "Show an Excel user form on demand:" & vbCrLf
        strOut = strOut & "Bill of Material" & vbCrLf     

        For i = 0 To UBound(strMaterial)
            strOut = strOut & strMaterial(i) & vbCrLf
        Next

        MsgBox strOut, vbInformation, "Excel Macro Functions"
    End If
End With

objExcel.DisplayAlerts = False
objExcel.ActiveWorkbook.Saved = True
objExcel.Quit
Set objExcel = Nothing  

Now for a test run.  Save the Excel worksheet and exit Excel.  In Windows Explorer, double-click the C:\ExcelMacroFunctionDemo.vbs file.  The second screen capture will likely be blank if you try to run the script as it is, but my output looks like the following:

Clicking OK displayed the following on my computer, but it will probably be blank on your computer:

Clicking OK causes the VBS macro to access the Excel macro code that retrieves information from the Windows registry and environment variables:

Next, the computer will ask for a mark up percent.  Specify a value, such as 50 or 100:

Next, the cabinet builder interface appears.  Pick a type of wood and a cabinet type.  The percentage specified earlier will be multiplied by the manufacture cost to arrive at the sales price.  A fake bill of material will appear near the bottom of the window.

When the Exit button is clicked, the bill of material is returned to the VBS script, and then displayed on the screen.

While this specific example might not be very useful, it does demonstrate how to use an Excel userform as an interface for a VBS script – and the username and password used to access the database are not in clear text in the VBS script.

Shortcut: save all of the following in the root of the C:\ drive and remove the .doc extension at the end of the filenames.

ExcelMacroFunctionDemo.xls

ExcelMacroFunctionDemo.vbs

BringToTop.exe (only needed on Vista and Windows 7)





Excel – Charting the Results of Oracle Analytic Functions

6 02 2010

February 6, 2010

This is a somewhat complicated example that builds a couple of sample tables, uses a SQL statement with the Oracle analytic function LEAD submitted through ADO in an Excel macro, and then presents the information on an Excel worksheet.  When the user clicks one of three buttons on the Excel worksheet, an Excel macro executes that then build charts using disconnected row sources – a disconnected ADO recordset is used to sort the data categories before pushing that data into the charts that are built on the fly.

To start, we need to build the sample tables.  The first two tables follow, a part list table and a vendor list table with random data:

CREATE TABLE PART_LIST (
  PART_ID VARCHAR2(30),
  PRODUCT_CODE VARCHAR2(30),
  COMMODITY_CODE VARCHAR2(30),
  PURCHASED CHAR(1),
  PRIMARY KEY (PART_ID));

INSERT INTO
  PART_LIST
SELECT
  DBMS_RANDOM.STRING('Z',10),
  DBMS_RANDOM.STRING('Z',1),
  DBMS_RANDOM.STRING('Z',1),
  DECODE(ROUND(DBMS_RANDOM.VALUE(1,2)),1,'Y','N')
FROM
  DUAL
CONNECT BY
  LEVEL<=50000;

COMMIT;

CREATE TABLE VENDOR_LIST (
  VENDOR_ID VARCHAR2(30),
  PRIMARY KEY (VENDOR_ID));

INSERT INTO
  VENDOR_LIST
SELECT
  DBMS_RANDOM.STRING('Z',10)
FROM
  DUAL
CONNECT BY
  LEVEL<=100; 

COMMIT;

Next, we need to build a purchase transaction history table, allowing a single part to be purchased from 10 randomly selected vendors of the 100 vendors.  This is actually a Cartesian join, but we need to force it to handled as a nested loop join so that we will have a different set of 10 vendors for each PART_ID:

CREATE TABLE PURCHASE_HISTORY (
  TRANSACTION_ID NUMBER,
  VENDOR_ID VARCHAR2(30),
  PART_ID VARCHAR2(30),
  UNIT_PRICE NUMBER(12,2),
  PURCHASE_DATE DATE,
  PRIMARY KEY (TRANSACTION_ID));

INSERT INTO
  PURCHASE_HISTORY
SELECT /*+ ORDERED USE_NL(PL VL) */
  ROWNUM,
  VL.VENDOR_ID,
  PL.PART_ID,
  VL.UNIT_PRICE,
  VL.PURCHASE_DATE
FROM
  PART_LIST PL,
  (SELECT
     'A' MIN_PART,
     'ZZZZZZZZZZZ' MAX_PART,
     VENDOR_ID,
     UNIT_PRICE,
     PURCHASE_DATE,
     ROWNUM RN
  FROM
    (SELECT
      VENDOR_ID,
      ROUND(DBMS_RANDOM.VALUE(0,10000),2) UNIT_PRICE,
      TRUNC(SYSDATE) - ROUND(DBMS_RANDOM.VALUE(0,5000)) PURCHASE_DATE
    FROM
      VENDOR_LIST
    ORDER BY
      DBMS_RANDOM.VALUE)) VL
WHERE
  PL.PURCHASED='Y'
  AND VL.RN<=10
  AND PL.PART_ID BETWEEN VL.MIN_PART AND VL.MAX_PART;

COMMIT;

Before we start working in Excel, we need to put together a SQL statement so that we are able to determine by how much the price of a part fluctuates over time.  We will use the LEAD analytic function to allow us to compare the current row values with the next row values, and only output the row when either the VENDOR_ID changes or the UNIT_PRICE changes.  While the sample data potentially includes dates up to 5,000 days ago, we only want to consider dates up to 720 days ago for this example:

SELECT /*+ ORDERED */
  PH.PART_ID,
  PH.VENDOR_ID,
  PH.UNIT_PRICE,
  PH.LAST_VENDOR_ID,
  PH.LAST_UNIT_PRICE,
  PL.PRODUCT_CODE,
  PL.COMMODITY_CODE
FROM
  (SELECT
    PH.PART_ID,
    PH.VENDOR_ID,
    PH.UNIT_PRICE,
    PH.PURCHASE_DATE,
    LEAD(PH.VENDOR_ID,1,NULL) OVER (PARTITION BY PART_ID ORDER BY PURCHASE_DATE DESC) LAST_VENDOR_ID,
    LEAD(PH.UNIT_PRICE,1,NULL) OVER (PARTITION BY PART_ID ORDER BY PURCHASE_DATE DESC) LAST_UNIT_PRICE
  FROM
    PURCHASE_HISTORY PH
  WHERE
    PH.PURCHASE_DATE>=TRUNC(SYSDATE-720)) PH,
  PART_LIST PL
WHERE
  PH.PART_ID=PL.PART_ID
  AND (PH.VENDOR_ID<>NVL(PH.LAST_VENDOR_ID,'-')
    OR PH.UNIT_PRICE<>NVL(PH.LAST_UNIT_PRICE,-1))
ORDER BY
  PH.PART_ID,
  PH.PURCHASE_DATE DESC;

The output of the above SQL statement might look something like this:

PART_ID    VENDOR_ID  UNIT_PRICE LAST_VENDO LAST_UNIT_PRICE P C
---------- ---------- ---------- ---------- --------------- - -
AAAFWXDGOR HHJAWQCYIV    1773.67 RPKWXSTFDS         5841.37 I T
AAAFWXDGOR RPKWXSTFDS    5841.37                            I T
AABDVNQJBS BBOSDBKYBR    4034.07                            D J
AABNDOOTTV HQBZXICKQM    2932.36                            C G
AABPRKFTLG NKYJQJXGJN     242.18 HHJAWQCYIV         1997.01 F I
AABPRKFTLG HHJAWQCYIV    1997.01                            F I
AACHFXHCDC SZWNZCRUWZ    3562.43                            P G
AACNAAOZWE JEYKZFIKJU    4290.12                            L N
AAEAYOLWMN DNDYVXUZVZ    4431.63                            K T
AAFLKRJTCO QPXIDOEDTI    8613.52                            Q G
AAGDNYXQGW BZFMNYJVBP     911.06 RPKWXSTFDS         2813.39 B L
AAGDNYXQGW RPKWXSTFDS    2813.39                            B L
AAGMKTQITK RAGVQSBHKW    9221.90 BCIRRDLHAN         8541.34 S W
AAGMKTQITK BCIRRDLHAN    8541.34 CWQNPITMBE         5611.73 S W
AAGMKTQITK CWQNPITMBE    5611.73                            S W
AAINVDSSWC CQXRSIWOIL    2690.31 BBOSDBKYBR         1707.15 K R
AAINVDSSWC BBOSDBKYBR    1707.15 QFPGRYTYUM         9158.98 K R
AAINVDSSWC QFPGRYTYUM    9158.98                            K R
AALCTODILL NKYJQJXGJN    2116.94                            K M
AAMAUJIWLF LPMSAUJGHR    6294.19 CNHZFDEWIH         4666.58 L P
AAMAUJIWLF CNHZFDEWIH    4666.58 SZWNZCRUWZ         2096.59 L P
AAMAUJIWLF SZWNZCRUWZ    2096.59                            L P
AAMYBVKFQC GLVKOCSHSF     265.63 PNGVEEYGKA         5869.67 X Z
AAMYBVKFQC PNGVEEYGKA    5869.67                            X Z
AANVGRNFEX NFHOKCKLDN    3961.42                            Q O
...

Now we need to switch over to Excel.  Create four ActiveX command buttons named cmdInitialize, cmdComparePC, cmdCompareCC, cmdCompareVendorID.  Name the worksheet OracleAnalyticTest, as shown below:

Right-click the OracleAnalyticTest worksheet and select View Code.  See this blog article to determine how to enable macros in Excel 2007 (if you have not already turned on this feature) and add a reference to the Microsoft ActiveX Data Objects 2.8 (or 6.0) Library.  We will also need to add a reference to the Microsoft ActiveX Data Objects Recordset 2.8 (or 6.0) Library.  Next, we add the code to the cmdInitialize button:

Option Explicit 'Forces all variables to be declared

Dim dbDatabase As New ADODB.Connection
Dim strDatabase As String
Dim strUserName As String
Dim strPassword As String

Private Function ConnectDatabase() As Integer
    Dim intResult As Integer

    On Error Resume Next

    If dbDatabase.State <> 1 Then
        'Connection to the database if closed, specify the database name, a username, and password
        strDatabase = "MyDB"
        strUserName = "MyUser"
        strPassword = "MyPassword"

        'Connect to the database
        'Oracle connection string
        dbDatabase.ConnectionString = "Provider=OraOLEDB.Oracle;Data Source=" & strDatabase & ";User ID=" & strUserName & ";Password=" & strPassword & ";ChunkSize=1000;FetchSize=100;"

        dbDatabase.ConnectionTimeout = 40
        dbDatabase.CursorLocation = adUseClient
        dbDatabase.Open

        If (dbDatabase.State <> 1) Or (Err <> 0) Then
            intResult = MsgBox("Could not connect to the database.  Check your user name and password." & vbCrLf & Error(Err), 16, "Excel Demo")

            ConnectDatabase = False
        Else
            ConnectDatabase = True
        End If
    Else
        ConnectDatabase = True
    End If
End Function

Private Sub cmdInitialize_Click()
    Dim i As Integer
    Dim intResult As Integer
    Dim lngRow As Long
    Dim strSQL As String
    Dim snpData As ADODB.Recordset

    On Error Resume Next

    Sheets("OracleAnalyticTest").ChartObjects.Delete
    Sheets("OracleAnalyticTest").Rows("4:10000").Delete Shift:=xlUp

    intResult = ConnectDatabase

    If intResult = True Then
        Set snpData = New ADODB.Recordset

        strSQL = "SELECT /*+ ORDERED */" & vbCrLf
        strSQL = strSQL & "  PH.PART_ID," & vbCrLf
        strSQL = strSQL & "  PH.VENDOR_ID," & vbCrLf
        strSQL = strSQL & "  PH.UNIT_PRICE," & vbCrLf
        strSQL = strSQL & "  PH.LAST_VENDOR_ID," & vbCrLf
        strSQL = strSQL & "  PH.LAST_UNIT_PRICE," & vbCrLf
        strSQL = strSQL & "  PL.PRODUCT_CODE," & vbCrLf
        strSQL = strSQL & "  PL.COMMODITY_CODE" & vbCrLf
        strSQL = strSQL & "FROM" & vbCrLf
        strSQL = strSQL & "  (SELECT" & vbCrLf
        strSQL = strSQL & "    PH.PART_ID," & vbCrLf
        strSQL = strSQL & "    PH.VENDOR_ID," & vbCrLf
        strSQL = strSQL & "    PH.UNIT_PRICE," & vbCrLf
        strSQL = strSQL & "    PH.PURCHASE_DATE," & vbCrLf
        strSQL = strSQL & "    LEAD(PH.VENDOR_ID,1,NULL) OVER (PARTITION BY PART_ID ORDER BY PURCHASE_DATE DESC) LAST_VENDOR_ID," & vbCrLf
        strSQL = strSQL & "    LEAD(PH.UNIT_PRICE,1,NULL) OVER (PARTITION BY PART_ID ORDER BY PURCHASE_DATE DESC) LAST_UNIT_PRICE" & vbCrLf
        strSQL = strSQL & "  FROM" & vbCrLf
        strSQL = strSQL & "    PURCHASE_HISTORY PH" & vbCrLf
        strSQL = strSQL & "  WHERE" & vbCrLf
        strSQL = strSQL & "    PH.PURCHASE_DATE>=TRUNC(SYSDATE-270)) PH," & vbCrLf
        strSQL = strSQL & "  PART_LIST PL" & vbCrLf
        strSQL = strSQL & "WHERE" & vbCrLf
        strSQL = strSQL & "  PH.PART_ID=PL.PART_ID" & vbCrLf
        strSQL = strSQL & "  AND (PH.VENDOR_ID<>NVL(PH.LAST_VENDOR_ID,'-')" & vbCrLf
        strSQL = strSQL & "    OR PH.UNIT_PRICE<>NVL(PH.LAST_UNIT_PRICE,-1))" & vbCrLf
        strSQL = strSQL & "ORDER BY" & vbCrLf
        strSQL = strSQL & "  PH.PART_ID," & vbCrLf
        strSQL = strSQL & "  PH.PURCHASE_DATE DESC"
        snpData.Open strSQL, dbDatabase

        If snpData.State = 1 Then
            Application.ScreenUpdating = False

            For i = 0 To snpData.Fields.Count - 1
                ActiveSheet.Cells(3, i + 1).Value = snpData.Fields(i).Name
            Next i
            ActiveSheet.Range(ActiveSheet.Cells(3, 1), ActiveSheet.Cells(3, snpData.Fields.Count)).Font.Bold = True

            ActiveSheet.Range("A4").CopyFromRecordset snpData

            'Auto-fit up to 26 columns
            ActiveSheet.Columns("A:" & Chr(64 + snpData.Fields.Count)).AutoFit
            ActiveSheet.Range("A4").Select
            ActiveWindow.FreezePanes = True

            'Remove duplicate rows with the same PART ID
            lngRow = 4
            Do While lngRow < Sheets("OracleAnalyticTest").UsedRange.Rows.Count + 2
                If Sheets("OracleAnalyticTest").Cells(lngRow, 1).FormulaR1C1 = "" Then
                    'Past the end of the rows
                    Exit Do
                End If
                If Sheets("OracleAnalyticTest").Cells(lngRow - 1, 1).FormulaR1C1 = Sheets("OracleAnalyticTest").Cells(lngRow, 1).FormulaR1C1 Then
                    'Found a duplicate row, delete it
                    Sheets("OracleAnalyticTest").Rows(lngRow).Delete Shift:=xlUp
                Else
                    lngRow = lngRow + 1
                End If
            Loop
            snpData.Close

            Application.ScreenUpdating = True
        End If
    End If

    Set snpData = Nothing
End Sub

The cmdInitialize_Click subroutine retrieves the data from the database using the supplied SQL statement and writes that information to the worksheet.  The macro then eliminates subsequent rows if the part ID is identical to the previous part ID (this step would not have been required if we modified the SQL statement to use the ROW_NUMBER analytic function, and eliminate all rows where the ROW_NUMBER value is not 1).  Once you add the above code, you should be able to switch back to the Excel worksheet, turn off Design Mode, and click the Initialize button.

Unfortunately, this example will retrieve too many rows with too little variation in the PRODUCT_CODE and COMMODITY_CODE columns (just 26 distinct values), so it might be a good idea to delete all rows below row 1004.  Now we need to switch back to the Microsoft Visual Basic editor and add the code for the other three buttons.  Note that this code takes advantage of gradient shading in Excel 2007 charts, so some modification might be necessary on Excel 2003 and earlier.

Private Sub cmdCompareCC_Click()
    Dim i As Long
    Dim intCount As Integer
    Dim intChartNumber As Integer
    Dim lngRows As Long
    Dim dblValues() As Double
    Dim strValueNames() As String
    Dim snpDataList As ADOR.Recordset

    On Error Resume Next

    Sheets("OracleAnalyticTest").ChartObjects.Delete
    Sheets("OracleAnalyticTest").Cells(4, 1).Select
    lngRows = Sheets("OracleAnalyticTest").UsedRange.Rows.Count + 2

    'Set up to use ADOR to automatically sort the product codes
    Set snpDataList = New ADOR.Recordset
    snpDataList.Fields.Append "commodity_code", adVarChar, 30
    snpDataList.Open

    'Pick up a distinct list of commodity codes
    For i = 4 To lngRows
        'Only include those commodity codes with price changes
        If (Sheets("OracleAnalyticTest").Cells(i, 5).Value <> 0) And (Round(Sheets("OracleAnalyticTest").Cells(i, 3).Value - Sheets("OracleAnalyticTest").Cells(i, 5).Value, 2) <> 0) Then
            If snpDataList.RecordCount > 0 Then
                snpDataList.MoveFirst
            End If
            snpDataList.Find ("commodity_code = '" & Sheets("OracleAnalyticTest").Cells(i, 7) & "'")
            If snpDataList.EOF Then
                'Did not find a matching record
                snpDataList.AddNew
                snpDataList("commodity_code") = Sheets("OracleAnalyticTest").Cells(i, 7).Value
                snpDataList.Update
            End If
        End If
    Next i
    snpDataList.Sort = "commodity_code"

    'Find the matching rows for each product code
    snpDataList.MoveFirst
    Do While Not snpDataList.EOF
        intCount = 0
        ReDim dblValues(250)
        ReDim strValueNames(250)
        For i = 4 To lngRows
            If intCount >= 250 Then
                'Excel charts only permit about 250 data points when created with this method
                Exit For
            End If
            If Sheets("OracleAnalyticTest").Cells(i, 7).Value = snpDataList("commodity_code") Then
                'Found a row with this product code
                If (Sheets("OracleAnalyticTest").Cells(i, 5).Value <> 0) And (Round(Sheets("OracleAnalyticTest").Cells(i, 3).Value - Sheets("OracleAnalyticTest").Cells(i, 5).Value, 2) <> 0) Then
                    'Price change was found
                    dblValues(intCount) = Round(Sheets("OracleAnalyticTest").Cells(i, 3).Value - Sheets("OracleAnalyticTest").Cells(i, 5).Value, 2)
                    strValueNames(intCount) = Sheets("OracleAnalyticTest").Cells(i, 1).FormulaR1C1
                    intCount = intCount + 1
                End If
            End If
        Next i

        'Set the arrays to the exact number of elements, first element at position 0
        ReDim Preserve dblValues(intCount - 1)
        ReDim Preserve strValueNames(intCount - 1)

        intChartNumber = intChartNumber + 1
        With Sheets("OracleAnalyticTest").ChartObjects.Add(10 * intChartNumber, 60 + 10 * intChartNumber, 400, 300)
            .Chart.SeriesCollection.NewSeries
            .Chart.SeriesCollection(1).Values = dblValues
            .Chart.SeriesCollection(1).XValues = strValueNames
            .Chart.Axes(1).CategoryType = 2
            .Chart.HasLegend = False

            .Chart.HasTitle = True
            .Chart.ChartTitle.Text = "Price Changes by Commodity Code: " & snpDataList("commodity_code")

            .Chart.Axes(xlCategory, xlPrimary).HasTitle = True
            .Chart.Axes(xlCategory, xlPrimary).AxisTitle.Characters.Text = "Part ID"
            .Chart.Axes(xlValue, xlPrimary).HasTitle = True
            .Chart.Axes(xlValue, xlPrimary).AxisTitle.Characters.Text = "Unit Cost Change"

            .Chart.SeriesCollection(1).HasDataLabels = True
            .Chart.SeriesCollection(1).HasLeaderLines = True

            With .Chart.PlotArea.Border
                .ColorIndex = 16
                .Weight = xlThin
                .LineStyle = xlContinuous
            End With

            .Chart.PlotArea.Fill.OneColorGradient Style:=msoGradientHorizontal, Variant:=2, Degree:=0.756847486076142
            .Chart.PlotArea.Fill.ForeColor.SchemeColor = 23
            .Chart.PlotArea.Fill.Visible = True
            With .Chart.PlotArea.Border
                .ColorIndex = 57
                .Weight = xlThin
                .LineStyle = xlContinuous
            End With

            .Chart.SeriesCollection(1).Fill.OneColorGradient Style:=msoGradientVertical, Variant:=4, Degree:=0.2
            .Chart.SeriesCollection(1).Fill.Visible = True
            .Chart.SeriesCollection(1).Fill.ForeColor.SchemeColor = 4

            .Chart.Axes(xlValue).MajorGridlines.Border.ColorIndex = 2
            With .Chart.SeriesCollection(1).DataLabels.Font
                .Name = "Arial"
                .FontStyle = "Regular"
                .Size = 8
                .Color = RGB(255, 255, 255)
            End With
            With .Chart.Axes(xlCategory).TickLabels.Font
                .Name = "Arial"
                .FontStyle = "Regular"
                .Size = 8
                .Color = RGB(255, 255, 255)
            End With
            With .Chart.ChartTitle.Font
                .Name = "Arial"
                .FontStyle = "Bold"
                .Size = 16
                .Color = RGB(0, 0, 255)
            End With
        End With
        snpDataList.MoveNext
    Loop

    Set snpDataList = Nothing
End Sub

Private Sub cmdComparePC_Click()
    Dim i As Long
    Dim intCount As Integer
    Dim intChartNumber As Integer
    Dim lngRows As Long
    Dim dblValues() As Double
    Dim strValueNames() As String
    Dim snpDataList As ADOR.Recordset

    On Error Resume Next

    Sheets("OracleAnalyticTest").ChartObjects.Delete
    Sheets("OracleAnalyticTest").Cells(4, 1).Select
    lngRows = Sheets("OracleAnalyticTest").UsedRange.Rows.Count + 2

    'Set up to use ADOR to automatically sort the product codes
    Set snpDataList = New ADOR.Recordset
    snpDataList.Fields.Append "product_code", adVarChar, 30
    snpDataList.Open

    'Pick up a distinct list of product codes
    For i = 4 To lngRows
        'Only include those product codes with price changes
        If (Sheets("OracleAnalyticTest").Cells(i, 5).Value <> 0) And (Round(Sheets("OracleAnalyticTest").Cells(i, 3).Value - Sheets("OracleAnalyticTest").Cells(i, 5).Value, 2) <> 0) Then
            If snpDataList.RecordCount > 0 Then
                snpDataList.MoveFirst
            End If
            snpDataList.Find ("product_code = '" & Sheets("OracleAnalyticTest").Cells(i, 6) & "'")
            If snpDataList.EOF Then
                'Did not find a matching record
                snpDataList.AddNew
                snpDataList("product_code") = Sheets("OracleAnalyticTest").Cells(i, 6).Value
                snpDataList.Update
            End If
        End If
    Next i
    snpDataList.Sort = "product_code"

    'Find the matching rows for each product code
    snpDataList.MoveFirst
    Do While Not snpDataList.EOF
        intCount = 0
        ReDim dblValues(250)
        ReDim strValueNames(250)
        For i = 4 To lngRows
            If intCount >= 250 Then
                'Excel charts only permit about 250 data points when created with this method
                Exit For
            End If
            If Sheets("OracleAnalyticTest").Cells(i, 6).Value = snpDataList("product_code") Then
                'Found a row with this product code
                If (Sheets("OracleAnalyticTest").Cells(i, 5).Value <> 0) And (Round(Sheets("OracleAnalyticTest").Cells(i, 3).Value - Sheets("OracleAnalyticTest").Cells(i, 5).Value, 2) <> 0) Then
                    'Price change was found
                    dblValues(intCount) = Round(Sheets("OracleAnalyticTest").Cells(i, 3).Value - Sheets("OracleAnalyticTest").Cells(i, 5).Value, 2)
                    strValueNames(intCount) = Sheets("OracleAnalyticTest").Cells(i, 1).FormulaR1C1
                    intCount = intCount + 1
                End If
            End If
        Next i

        'Set the arrays to the exact number of elements, first element at position 0
        ReDim Preserve dblValues(intCount - 1)
        ReDim Preserve strValueNames(intCount - 1)

        intChartNumber = intChartNumber + 1

        With Sheets("OracleAnalyticTest").ChartObjects.Add(10 * intChartNumber, 60 + 10 * intChartNumber, 400, 300)
            .Chart.SeriesCollection.NewSeries
            .Chart.SeriesCollection(1).Values = dblValues
            .Chart.SeriesCollection(1).XValues = strValueNames
            .Chart.Axes(1).CategoryType = 2
            .Chart.HasLegend = False

            .Chart.HasTitle = True
            .Chart.ChartTitle.Text = "Price Changes by Product Code: " & snpDataList("product_code")

            .Chart.Axes(xlCategory, xlPrimary).HasTitle = True
            .Chart.Axes(xlCategory, xlPrimary).AxisTitle.Characters.Text = "Part ID"
            .Chart.Axes(xlValue, xlPrimary).HasTitle = True
            .Chart.Axes(xlValue, xlPrimary).AxisTitle.Characters.Text = "Unit Cost Change"

            .Chart.SeriesCollection(1).HasDataLabels = True
            .Chart.SeriesCollection(1).HasLeaderLines = True

            With .Chart.PlotArea.Border
                .ColorIndex = 16
                .Weight = xlThin
                .LineStyle = xlContinuous
            End With

            .Chart.PlotArea.Fill.OneColorGradient Style:=msoGradientHorizontal, Variant:=2, Degree:=0.756847486076142
            .Chart.PlotArea.Fill.ForeColor.SchemeColor = 23
            .Chart.PlotArea.Fill.Visible = True
            With .Chart.PlotArea.Border
                .ColorIndex = 57
                .Weight = xlThin
                .LineStyle = xlContinuous
            End With

            .Chart.SeriesCollection(1).Fill.OneColorGradient Style:=msoGradientVertical, Variant:=4, Degree:=0.2
            .Chart.SeriesCollection(1).Fill.Visible = True
            .Chart.SeriesCollection(1).Fill.ForeColor.SchemeColor = 5

            .Chart.Axes(xlValue).MajorGridlines.Border.ColorIndex = 2
            With .Chart.SeriesCollection(1).DataLabels.Font
                .Name = "Arial"
                .FontStyle = "Regular"
                .Size = 8
                .Color = RGB(255, 255, 255)
            End With
            With .Chart.Axes(xlCategory).TickLabels.Font
                .Name = "Arial"
                .FontStyle = "Regular"
                .Size = 8
                .Color = RGB(255, 255, 255)
            End With
            With .Chart.ChartTitle.Font
                .Name = "Arial"
                .FontStyle = "Bold"
                .Size = 16
                .Color = RGB(0, 0, 255)
            End With
        End With

        snpDataList.MoveNext
    Loop

    Set snpDataList = Nothing
End Sub

Private Sub cmdCompareVendorID_Click()
    Dim i As Long
    Dim intCount As Integer
    Dim intChartNumber As Integer
    Dim lngRows As Long
    Dim dblValues() As Double
    Dim strValueNames() As String
    Dim snpDataList As ADOR.Recordset

    On Error Resume Next

    Sheets("OracleAnalyticTest").ChartObjects.Delete
    Sheets("OracleAnalyticTest").Cells(4, 1).Select
    lngRows = Sheets("OracleAnalyticTest").UsedRange.Rows.Count + 2

    'Set up to use ADOR to automatically sort the product codes
    Set snpDataList = New ADOR.Recordset
    snpDataList.Fields.Append "vendor_id", adVarChar, 30
    snpDataList.Open

    'Pick up a distinct list of vendor IDs
    For i = 4 To lngRows
        'Only include those vendor IDs with price changes
        If (Sheets("OracleAnalyticTest").Cells(i, 5).Value <> 0) And (Round(Sheets("OracleAnalyticTest").Cells(i, 3).Value - Sheets("OracleAnalyticTest").Cells(i, 5).Value, 2) <> 0) Then
            If snpDataList.RecordCount > 0 Then
                snpDataList.MoveFirst
            End If
            snpDataList.Find ("vendor_id = '" & Sheets("OracleAnalyticTest").Cells(i, 2) & "'")
            If snpDataList.EOF Then
                'Did not find a matching record
                snpDataList.AddNew
                snpDataList("vendor_id") = Sheets("OracleAnalyticTest").Cells(i, 2).Value
                snpDataList.Update
            End If
        End If
    Next i
    snpDataList.Sort = "vendor_id"

    'Find the matching rows for each product code
    snpDataList.MoveFirst
    Do While Not snpDataList.EOF
        intCount = 0
        ReDim dblValues(250)
        ReDim strValueNames(250)
        For i = 4 To lngRows
            If intCount >= 250 Then
                'Excel charts only permit about 250 data points when created with this method
                Exit For
            End If
            If Sheets("OracleAnalyticTest").Cells(i, 2).Value = snpDataList("vendor_id") Then
                'Found a row with this product code
                If (Sheets("OracleAnalyticTest").Cells(i, 5).Value <> 0) And (Round(Sheets("OracleAnalyticTest").Cells(i, 3).Value - Sheets("OracleAnalyticTest").Cells(i, 5).Value, 2) <> 0) Then
                    'Price change was found
                    dblValues(intCount) = Round(Sheets("OracleAnalyticTest").Cells(i, 3).Value - Sheets("OracleAnalyticTest").Cells(i, 5).Value, 2)
                    strValueNames(intCount) = Sheets("OracleAnalyticTest").Cells(i, 1).FormulaR1C1
                    intCount = intCount + 1
                End If
            End If
        Next i

        'Set the arrays to the exact number of elements, first element at position 0
        ReDim Preserve dblValues(intCount - 1)
        ReDim Preserve strValueNames(intCount - 1)

        intChartNumber = intChartNumber + 1

        With Sheets("OracleAnalyticTest").ChartObjects.Add(10 * intChartNumber, 60 + 10 * intChartNumber, 400, 300)
            .Chart.SeriesCollection.NewSeries
            .Chart.SeriesCollection(1).Values = dblValues
            .Chart.SeriesCollection(1).XValues = strValueNames
            .Chart.Axes(1).CategoryType = 2
            .Chart.HasLegend = False

            .Chart.HasTitle = True
            .Chart.ChartTitle.Text = "Price Changes by Vendor: " & snpDataList("vendor_id")

            .Chart.Axes(xlCategory, xlPrimary).HasTitle = True
            .Chart.Axes(xlCategory, xlPrimary).AxisTitle.Characters.Text = "Part ID"
            .Chart.Axes(xlValue, xlPrimary).HasTitle = True
            .Chart.Axes(xlValue, xlPrimary).AxisTitle.Characters.Text = "Unit Cost Change"

            .Chart.SeriesCollection(1).HasDataLabels = True
            .Chart.SeriesCollection(1).HasLeaderLines = True

            With .Chart.PlotArea.Border
                .ColorIndex = 16
                .Weight = xlThin
                .LineStyle = xlContinuous
            End With

            .Chart.PlotArea.Fill.OneColorGradient Style:=msoGradientHorizontal, Variant:=2, Degree:=0.756847486076142
            .Chart.PlotArea.Fill.ForeColor.SchemeColor = 23
            .Chart.PlotArea.Fill.Visible = True
            With .Chart.PlotArea.Border
                .ColorIndex = 57
                .Weight = xlThin
                .LineStyle = xlContinuous
            End With

            .Chart.SeriesCollection(1).Fill.OneColorGradient Style:=msoGradientVertical, Variant:=4, Degree:=0.2
            .Chart.SeriesCollection(1).Fill.Visible = True
            .Chart.SeriesCollection(1).Fill.ForeColor.SchemeColor = 45

            .Chart.Axes(xlValue).MajorGridlines.Border.ColorIndex = 2
            With .Chart.SeriesCollection(1).DataLabels.Font
                .Name = "Arial"
                .FontStyle = "Regular"
                .Size = 8
                .Color = RGB(255, 255, 255)
            End With
            With .Chart.Axes(xlCategory).TickLabels.Font
                .Name = "Arial"
                .FontStyle = "Regular"
                .Size = 8
                .Color = RGB(255, 255, 255)
            End With
            With .Chart.ChartTitle.Font
                .Name = "Arial"
                .FontStyle = "Bold"
                .Size = 16
                .Color = RGB(0, 0, 255)
            End With
        End With
        snpDataList.MoveNext
    Loop

    Set snpDataList = Nothing
End Sub

If we switch back to the Excel worksheet, the remaining three buttons should now work.  Clicking each button will cause Excel to examine the data in the worksheet to locate all of the unique values for PRODUCT_CODE, COMMODITY_CODE, or VENDOR_ID, and then sort the list in alphabetical order, and build a chart for each of the part IDs that fall into those categories.  The results for my test run of each button looks like the following three pictures.

You can, of course, adapt the code to work with other SQL statements and modify the chart generating code to alter the chart type, colors, and fonts.





Faulty Quotes 6 – CPU Utilization

5 02 2010

February 5, 2010

(Back to the Previous Post in the Series) (Forward to the Next Post in the Series)

The ideal level of CPU utilization in a server is an interesting topic.  Google (and other search engines) find a number of different web pages that advocate that 100% CPU utilization is ideal, CPU utilization at 95% is likely catastrophic, significant queuing for CPU time begins when the CPUs are 75% to 80% busy, as well as a number of other interesting nuggets of information.  It is important to keep in mind that at any one instant, a CPU (or core or CPU instruction thread) is either 100% busy or 0% busy – at any one instant a CPU cannot be 75% busy.  The 75% or 95% utilization figures found on various web sites, in books, and in presentations are actually an average utilization between two points in time – whether those two points in time represent 0.000001 seconds, 24 hours, or somewhere in between could be very important when trying to determine if there is an excessive CPU utilization issue that causes service level agreement problem (or “slowness” problems reported by end-users).

Assume that in a one minute time period, the CPU utilization in a server is 75% – is that suitable, or is that undesirable, or not enough information is available to make an educated guess?  Good !?  Maybe good?  Bad?  Keep in mind that the CPU utilization is an average utilization between a starting time point and an ending time point – much like with a Statspack/AWR report, if you look at too large of a time period, significant problems may be masked (hidden from view) when the statistics from the time intervals containing problems are averaged over a long time period.  The 75% CPU utilization could indicate that for every three of four points in time the CPU had work that needed to be performed.  The 75% CPU utilization might also indicate that there was intense competition for the CPU time by many tasks for the first 45 seconds, followed by a complete absence of the need for CPU time in the last 15 seconds of the one minute time period.  For the many tasks competing for CPU time in the first 45 seconds, what might normally complete in one second might have actually required close to 45 seconds due to the operating system attempting to allocate portions of the server’s CPU time to each of the tasks that needed to use the CPU.  The tasks queue up while waiting for their turn for processing, in what is known as the CPU run queue.  As more processes enter the run queue, it takes longer for each process to perform each unit of their normal processing.  This is where the topic of queuing theory becomes very important.  Two very helpful books that discuss queuing theory as it applies to Oracle Database functionality are “Optimizing Oracle Performance” (by Cary Millsap with Jeff Holt) and “Forecasting Oracle Performance” (by Craig Shallahamer).  (Note: This example used one minute as the time interval for measuring CPU utilization in order to rationalize the competition for CPU resources into terms that are easily understood – assuming that a given 3GHz processor is only able to perform one operation at a time, that processor is capable of performing 3,000,000,000 operations per second – 180,000,000,000 operations in that one minute.)

There are a couple of different formulas used in queuing theory, including the Erlang C function, Little’s Law, and Kendall’s Notation.  I will not go into significant detail here on the different queuing theory models, but I will provide a simple example.  Assume that you enter a grocery store that has 10 checkout lanes (think of this like 10 CPUs in a database server).  When it is time to pay for the items in your cart, a person working for the store directs you into one of the 10 checkout lanes.  If anyone else is directed into the same checkout lane as you, you will need to alternate with that person at the checkout counter every 10 seconds – when your 10 second time period is up, you will need to load up everything placed on the conveyor belt and allow the other person to unload their items on the belt to use the checkout lane for 10 seconds  (this loading and unloading of items could be time consuming).  If anyone else is directed into your checkout lane, that person will also be able to use the checkout counter for 10 second intervals.  In short order, what would have required 5 minutes to complete is now requiring 30 minutes.  If the line grows too long in one checkout lane, there might be a chance to jump into a different checkout lane used by fewer people, possibly once a minute (some Linux operating systems will potentially move a process from one CPU to a less busy CPU every 200ms).  Jumping into a different checkout lane not only allows you to check out faster, but also allows the people who remain in the original line to check out faster.  The above is a very rough outline of queuing theory.  If the customer expects to check out in no more than 10 minutes, how many lanes are necessary, given that the customers arrive at a random rate, and we must meet the target 99% of the time.

CPU queuing is not a linear problem – 100% CPU utilization is not twice as bad as 50% CPU utilization, it is much worse than that.  Some of the articles below explain this concept very well – a Google search found a couple of interesting articles/presentations that computer science professors assembled for various classes – you might find it interesting to read some of those documents that are found in the .edu domain (it appears that none of those links made it into this blog article).  Some operating systems use a single run queue (for instance, Windows, and Linux prior to the 2.6 kernel release), with the end result of effectively evenly distributing the CPU load between CPUs, causing the processes to constantly jump from one CPU to another (this likely reduces the effectiveness of the CPU caches – pulling everything off the conveyor belt in the analogy).  Other operating systems have a separate run queue for each CPU, which keeps the process running on the same CPU.  Quick quiz: If our 10 CPU server in this example has a run queue of 10 – does that mean that one process is in each of the 10 CPU run queues, or is it possible that all 10 processes will be in just one of the 10 run queues, or possibly something in between those two extremes?  Are all three scenarios equally good or equally bad?

Keep in mind that while sessions are in “wait events” that does not mean that the sessions are not consuming server CPU time.  A session in an Oracle wait event might motivate a significant amount of system (kernel) mode CPU time on behalf of the session.  Sending/receiving data through the network, disk accesses, inspection of the current date/time, and even reading eight bytes (a 64 bit word) from memory motivates the use of the server’s CPU time.  CPU saturation may lead to latch contention (note that latch contention may also lead to CPU saturation due to sessions spinning while attempting to acquire a latch), long-duration log file waits (log file sync, log file parallel write), cluster-related waits, increased duration of single-block and multiblock reads, and significant increases in server response time.

So, with the above in mind, just what did my Google search find?  In the following quotes, I have attempted to quote the bare minimum of each article so that the quote is not taken too far out of context (I am attempting to avoid changing the meaning of what is being quoted).

Oracle Performance Tuning 101” (Copyright 2001, directly from the book) by Gaja Vaidyanatha states:

“One of the classic myths about CPU utilization is that a system with 0 percent idle is categorized as a system undergoing CPU bottlenecks… It is perfectly okay to have a system with 0 percent idle, so long as the average runnable queue for the CPU is less than (2 x number of CPUs).”

http://asktom.oracle.com/pls/asktom/f?p=100:11:0::::P11_QUESTION_ID:6108562636780

“Are you at 100% utilization?  If not, you haven’t accomplished your job yet.  You cannot put CPU in the bank and save it for later.  So, if you are running with idle cycles you should be looking for more ways to use it.”

dba-oracle.com/t_high_cpu.htm

“Remember, all virtual memory servers are designed to drive CPU to 100%, and 100% CPU utilization is optimal, that’s how the server SMP architecture is designed.   You only have CPU enqueues when there are more tasks waiting for CPU, than you have CPU’s (your cpu_count)… Remember, it is not a cause for concern when the user + system CPU values approach 100 percent. This just means that the CPUs are working to their full potential.”

dba-oracle.com/t_tuning_cpu_usage_vmstat.htm

“Remember, it is not a cause for concern when the user + system CPU values approach 100 percent. This just means that the CPUs are working to their full potential. The only metric that identifies a CPU bottleneck is when the run queue (r value) exceeds the number of CPUs on the server.”

dba-oracle.com/t_monitor_cpu_unix.htm

“Within UNIX, the OS is geared to drive CPU consumption to 100%, so the best way to monitor CPU usage is by tracking the ‘r’ column in vmstat”

dba-oracle.com/t_detecting_windows_cpu_processor_bottlenecks.htm

“100% utilization DOES NOT always indicate any bottleneck. It just means that the CPU is busy!  You ONLY have a CPU bottleneck when the runqueue exceeds cpu_count.”

fast-track.cc/op_unix_79_identifying_high_cpu.htm

“Please note that it is not uncommon to see the CPU approach 100 percent even when the server is not overwhelmed with work. This is because the UNIX internal dispatchers will always attempt to keep the CPUs as busy as possible. This maximizes task throughput, but it can be misleading for a neophyte.”

dbaforums.org/oracle/index.php?showtopic=5552

“It’s normal for virtual memory systems to drive the CPU to 100%.

What you need to look for are CPU runqueues, not 100% values”

dbaforums.org/oracle/index.php?showtopic=9986

“No problem! Processors are designed to drive themselves up to 100%.

You are only CPU-bound when the runqueue exceeds the number of processors”

http://forums.oracle.com/forums/thread.jspa?messageID=2518290

“100% utilization is the optimal state. If you want to look for CPU bottlenecks, use vmstat and check the “r” (runqueue) column…  It’s not a claim, it’s a fact, according to the folks who built their servers!  The vendors who build the servers say that 100% CPU utilization is optimal, and they wrote both the OS and the underlying hardware… Every 1st year DBA noob panics at some point when they go into top and see that the CPU is at pegged at 100%.”

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

“All SMP architectures are designed to throttle-up the CPU quickly, and a 100% utilization DOES NOT mean an overload. It’s straight from Algorithms 101…  Just to make sure that you are not operating under “assumptions” here, I’m talking about server-side CPU consumption, on an SMP server running lots of concurrent tasks. The references to 100% CPU are as they display in standard OS monitors like lparstat, watch, sar and vmstat.  Also, don’t assume that all OS tasks have the same dispatching priority. In a server-side 100% CPU situation, some tasks may have enqueues, while other do not. That’s what ‘nice’ is for.”

http://books.google.com/books?id=cHHMDgKDXtIC&pg=PA112

“Remember, it is not a cause for concern when the user + system CPU values approach 100 percent.  This just means that the CPUs are working to their full potential. The only metric that identifies a CPU bottleneck is when the run queue (r value) exceeds the number of CPUs on the sever.”

——————–

Before deciding that a 100% CPU utilization is not only normal, but something we should all try to achieve, visit the following links and spend a little time reading the text near the quoted section of the document.

——————–

“Optimizing Oracle Performance” page 264, by Cary Millsap:

“On batch-only application systems, CPU utilization of less than 100% is bad if there is work waiting in the job queue. The goal of a batch-only system user is maximized throughput. If there is work waiting, then every second of CPU capacity left idle is a second of CPU capacity gone that can never be reclaimed. But be careful: pegging CPU utilization at 100% over long periods often causes OS scheduler thrashing, which can reduce throughput. On interactive-only systems, CPU utilization that stays to the right of the knee over long periods is bad. The goal of an interactive-only system user is minimized response time. When CPU utilization exceeds the knee in the response time curve, response time fluctuations become unbearable.”

“Forecasting Oracle Performance” page 71 by Craig Shallahamer:

 “With the CPU subsystem shown in Figure 3-7, queuing does not set in (that is response time does not significantly change) until utilization is around 80% (150% workload increase). The CPU queue time is virtually zero and then skyrockets because there are 32 CPUs. If the system had fewer CPUs, the slope, while still steep, would have been more gradual.”

“Forecasting Oracle Performance” page 195 by Craig Shallahamer:

“The high-risk solution would need to contain at least 22 CPUs. Because the reference ratios came from a 20 CPU machine, scalability is not significant. However, recommending a solution at 75% utilization is significant and probably reckless. At 75% utilization, the arrival rate is already well into the elbow of the curve. It would be extremely rare to recommend a solution at 75% utilization.”

http://forums.oracle.com/forums/thread.jspa?messageID=2518290

“First: check the following simple example of how wrong you can be in saying {‘using’ all of your CPU is a good thing} especially in a multi-user, shared memory environment such as an active Oracle instance. You see, although ‘using’ all of your CPU may be desirable if you don’t waste any of it, in a multi-user system you can waste a lot of CPU very easily – even when nobody goes off the run queue.”

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

“But it’s not ‘normal’ to drive CPUs to 100%. Except for extremely exotic circumstances (and that excludes database processing) it means you’ve overloading the system and wasting resources…  Consider the simple case of 8 queries running on 8 CPUs. They will be competing for the same cache buffers chains latches – which means that seven processes could be spinning on the same latch while the eighth is holding it. None of the processes ever need wait, but most of them could be wasting CPU most of the time.”

http://www.dell.com/downloads/global/solutions/public/White_Papers/hied_blackboard_whitepaper.pdf Page 19

“One of the sizing concepts that is independent of the server model is resource utilization. It is never a good idea to attempt to achieve 100% resource utilization. In the Blackboard benchmark tests, the optimum Application Server CPU Utilization was 75% to 90%. In general, clients should size all Application Servers to achieve no more than 75% CPU utilization. For database servers, the optimum CPU utilization is 80% in non-RAC mode. In RAC mode, clients should consider CPU utilization rates around 65% at peak usage periods to allow reserve capacity in case of cluster node failover.”

http://www-03.ibm.com/support/techdocs/atsmastr.nsf/5cb5ed706d254a8186256c71006d2e0a/546c74feec117c118625718400173a3e/$FILE/RDB-DesignAndTuning.doc

“The CPU utilization goal should be about 70 to 80% of the total CPU time. Lower utilization means that the CPU can cope better with peak workloads.  Workloads between 85% to 90% result in queuing delays for CPU resources, which affect response times. CPU utilization above 90% usually results in unacceptable response times.  While running batch jobs, backups, or loading large amounts of data, the CPU may be driven to high percentages, such as to 80 to 100%, to maximize throughput.”

11g R2 Performance Tuning Guide :

“Workload is an important factor when evaluating your system’s level of CPU utilization. During peak workload hours, 90% CPU utilization with 10% idle and waiting time can be acceptable. Even 30% utilization at a time of low workload can be understandable. However, if your system shows high utilization at normal workload, then there is no room for a peak workload.”

Oracle9i Application Server Oracle HTTP Server powered by Apache Performance Guide

“In addition to the minimum installation recommendations, your hardware resources need to be adequate for the requirements of your specific applications. To avoid hardware-related performance bottlenecks, each hardware component should operate at no more than 80% of capacity.”

Relational Database Design and Performance Tuning for DB2 Database Servers

Page 26: “When CPU utilization rises above 80%, the system overhead increases significantly to handle other tasks. The lifespan of each child process is longer and, as a result, the memory usage supporting those active concurrent processes increases significantly. At stable load, 10% login, and CPU utilization below 80%, the memory usage formula is as follows…”

Page 27: “When system load generates a high CPU utilization (>90%) some of the constituent processes do not have enough CPU resource to complete within a certain time and remain ‘active’.”

Oracle Database High Availability Best Practices 10g Release 2

“If you are experiencing high load (excessive CPU utilization of over 90%, paging and swapping), then you need to tune the system before proceeding with Data Guard. Use the V$OSSTAT or V$SYSMETRIC_HISTORY view to monitor system usage statistics from the operating system.”

“Optimizing Oracle Performance” page 317

“Oracle’s log file sync wait event is one of the first events to show increased latencies due to the time a process spends waiting in a CPU run queue.”

Metalink Doc ID 148176.1 “Diagnosing hardware configuration induced performance problems”

“In general your utilization on anything should never be over 75-80%…”

http://www.tomfarwellconsulting.com/Queuing%20Presentation.pdf

“Linear thinking is a common human process.  This notion implies that if an input increases by 20 percent the output of the system changes by 20 percent.

Computer response does not follow a linear curve. It is entirely possible that a change in computer input by 20 percent results in a change in output of hundreds of percent.”

http://www.mcguireconsulting.com/newsl_queuing.html

“This utilization-based multiplier increases exponentially and does so rapidly after the 50% utilization point, as shown in the graph below. The translation is: if a resource’s utilization is much beyond 50%, there is a higher probability that congestion will occur. Keep in mind that at 100% utilization, the delay goes to infinity, which is the direction of these curves.”

http://www.db2-dba.net/articles/Article-Usage%20Factor.html

“Request Service time =  ( Ideal Request Service time x  Usage factor ) / (1 – Usage factor )    where   0>=  Usage factor >= 1
The  Request Service time is proportional to U/(1-U).

As you can see from the simple plot above as U reaches 0.95  you are fast approaching the meltdown point.
As U gets closer to .95  the Service time of the system reacts violently and starts approaching infinity. 
The ‘system’  might be your  CPU , DISK, Network, employee or your motor car. 

It is just a bad idea to push the average resource utilization factor beyond 0.9, and the peak resource utilization factor beyond 0.95.”

http://databaseperformance.blogspot.com/2009/01/queuing-theory-resource-utilisation.html

“So an Oracle database server does conform to the general model in Queuing Theory of having lots of separate clients (the shadow servers) making requests on the resources in the system. And as a result, it does conform to the golden rule of high resource utilisation equals queues of pending requests.

As a result, 100% CPU utilization is very bad, and is symptomatic of very large queues of waiting processes. Queuing Theory also shows that above 50% utilization of a resource, there is always a request in the queue more often than not…  A general rule of thumb is to get worried at 80% utilization, as the number of concurrent requests will average something around four, and rises exponentially above this.”

http://kevinclosson.wordpress.com/2007/07/21/manly-men-only-use-solid-state-disk-for-redo-logging-lgwr-io-is-simple-but-not-lgwr-processing/

“Once LGWR loses his CPU it may be quite some time until he gets it back. For instance, if LGWR is preempted in the middle of trying to perform a redo buffer flush, there may be several time slices of execution for other processes before LGWR gets back on CPU…” Fix the CPU problem, and the other significant waits may decrease.

Newsflash – 100% CPU is Worse than You Think!

“Amazing. During my entire discussion of CPU load and process priorities I completely ignored the fact that I’m using 2 dual core cpus on that system, and that all Oracle processes use shared memory, which means shared resource, which means locks, which means resource wasting by waiting for locks. And this complicated the discussion, because 6 processes on 8 CPUs will also waste time waiting for locks. You don’t need 100% CPU to suffer from this.”

Opinions are bound to change over time.  The first two quotes are from OakTable Network members, and those quotes were originally written eight or nine years ago.  If you were to ask those two people today (or even shortly after the release of the “Optimizing Oracle Performance” book in 2003), they might state something a bit different about driving and then holding CPUs at 100% utilization.  Interestingly, holding a CPU at 100% utilization will cause its core temperature to gradually increase.  Logic in some of the CPUs will sense this increase in temperature and actually throttle back the speed of the CPU until the core temperature drops to acceptable levels.  Of course, when the CPU speed is throttled back, that potentially causes the CPU run queue to increase in length because the amount of work required for by each process has not decreased, while the number of CPU cycles per second available for performing work has decreased.  

More could be written on this subject, but I will leave it at this point for now (for instance, I could have mentioned process/thread priority gradually decreasing on some operating systems for those processes consuming a lot of CPU time).  Opinions, other than this article being too short (or too long)?  As you can probably tell from the quotes, CPU utilization issues are not just a special situation on a single operating system, or a special situation with a certain program (Oracle Database).