Testing removing subpartitions from a table with query testing package

I thought I would start this blog post before I finished this testing so I wouldn’t forget what I’m doing along the way.  Usually I just write something up after I’m done and then I may forget all I’ve done along the way.

We have a production table with tens of thousands of subpartitions and we are having long parse times on queries against this table.  It looks like the daily stats gathering job never finishes gathering stats on the table’s subpartitions and so it is running against them all day and then the queries get hung up with library cache locks and such.  We are on Exadata on 11.2.0.2 BP 20 (or is it 21?).

I don’t doubt for a second that removing the subpartitions will resolve the parsing issues but I’m concerned that some query’s performance will be degraded.  Of course the parsing issues are so bad that this may be a moot point because the problem most likely greatly exceeds any slowdown that removing the subpartitions would cause.

So, I am using my “TESTSELECT” package that I’ve written about earlier to test query performance with and without subpartitioning.  Here is a zip of the current version of the package: zip.  Here are the previous posts: p1, p2, p3.

Here are the steps I’ve done so far:

  1. Create empty partitioned copy of subpartitioned table on test database
  2. Copy rows from subpartitioned table to partitioned one
  3. Extract 1000 queries from production that include the subpartitioned table
  4. Copy the 1000 select statements from production to the test database
  5. Run the statements against the subpartitioned table

That’s where I’ve gotten so far today – 12/5/2013.

Here are some details:

Extract 1000 queries from production that include the subpartitioned table:

Truncate select_statements table and load:

truncate table select_statements;

begin

TEST_SELECT.collect_select_statements(
   max_number_selects=>1000,
   include_pattern1=> '%OWNER.TABLE_NAME%');

end;
/

OWNER.TABLE_NAME was really the actual production schema and table name.  These statements were run on production.

Copy the 1000 select statements from production to the test database;

First create a database link to production database from test:

create database link MYLINK
connect to myuser identified by mypassword
using
'(DESCRIPTION =                                                 
    (ADDRESS = (PROTOCOL = TCP)(HOST = exahost-scan)(PORT = 1521))
    (CONNECT_DATA =
      (SERVER = DEDICATED)
      (SERVICE_NAME = service.domain)
    )
  )';

select * from dual@mylink;

Now use package to copy the select statements over to test:

execute TEST_SELECT.copy_select_statements('MYLINK');

I ran this on my test database.

Run the statements against the subpartitioned table:

alter session set nls_date_format='DD-MON-YYYY';

truncate table test_results;

execute TEST_SELECT.execute_all('SUBPARTITIONED');

I ran this on test – it is still running now.  I ran it first without the session alter and got a bunch of invalid month errors in the results table.  I’ve done a simple dump of the results table to see how far I am:

select * 
from test_results
order by 
test_name,
sqlnumber;

Here are a couple of lines of output so far:

TEST_NAME                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                         SQLNUMBER SQL_ID        EXPLAIN_PLAN_HASH EXECUTE_PLAN_HASH ROWS_FETCHED ELAPSED_IN_SECONDS CPU_USED_BY_THIS_SESSION CONSISTENT_GETS DB_BLOCK_GETS PARSE_TIME_ELAPSED PHYSICAL_READS ERROR_MESSAGE
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ---------- ------------- ----------------- ----------------- ------------ ------------------ ------------------------ --------------- ------------- ------------------ -------------- ----------------------------------------------------------------
SUBPARTITIONED                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            1 1g2vpq70ha4z0                           132181740            0                  0                       47             545            24                 43              2
SUBPARTITIONED                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            2                                                                                                                                                                            ORA-01008: not all variables bound
SUBPARTITIONED                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            3 6z52mffn2ttka                           834663019            0                  3                      130          572231            14                  4         528910
SUBPARTITIONED                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            4 dpjruwgrt6hsr                          2715404655            0                  2                      133          572231            14                  4         528910

Once this is done I’ll change the queries to have my new partitioned table in place of the current subpartitioned one using a command like this:

execute TEST_SELECT.update_select_statements(
'ORIGSCHEMA.ORIGTABLE',
'NEWSCHEMA.NEWTABLE');

Then I’ll run with the partitioned table something like this:

alter session set nls_date_format='DD-MON-YYYY';

execute TEST_SELECT.execute_all('PARTITIONED');

Note that I don’t truncate the test_results table this time because I wan’t to save the earlier run’s results to compare to this one.

That’s it so far.  More updates when I make some progress.  356 of the 1000 queries against the subpartitioned table complete so far.

Update:  Up to 941.  Got a couple of errors and don’t want to fix the issue and rerun all 1000 of these so I updated the package with a new proc: reexecute_errored to just rerun the ones that have errors after the problem.

Friday update:

Here is some of the output from the subpartitioned table run:

Executed SQL number 1
Error on SQL number 2
ORA-01008: not all variables bound
Executed SQL number 3
Executed SQL number 4
Executed SQL number 5
...
Executed SQL number 663
Executed SQL number 664
Error on SQL number 665
ORA-06564: object MY_DIRECTORY does not exist
Error on SQL number 666
ORA-06564: object MY_DIRECTORY does not exist
Executed SQL number 667
Executed SQL number 668
...
Executed SQL number 1098
Executed SQL number 1099
Executed SQL number 1100

PL/SQL procedure successfully completed.

Elapsed: 06:04:46.27

Ran about 6 hours.  Three queries failed because my test user didn’t have privileges on a directory.  Ended up giving read on directory and write on directory grants to my test user.  Then I reran the errors queries using this new function:

alter session set nls_date_format='DD-MON-YYYY';

execute TEST_SELECT.reexecute_errored('SUBPARTITIONED');

I blew out an internal variable so I made an update today to just save the first 64 bytes of the error message in the results table.  It isn’t perfect but still helpful package.

After a couple of runs down to just the two selects with bind variables.  The package can’t test a select with a bind variable:

Error on SQL number 2
ORA-01008: not all variables bound
Error on SQL number 102
ORA-01008: not all variables bound

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.01

Now I did what I said above modifying the select statements and rerunning against the partitioned table.  I did back up the select_statements and test_results tables so I don’t lose the 6 hours of testing and query gathering by some sort of mistake.

Spent some more time today messing with the package while waiting for the second test to finish.  I built an example.sql script to run through all the procs and functions that are in the package and show how to use them.  The resources page will always have a link to the most recent zip.  FYI.  So far I’ve only tested the package on 11.2 – at least the latest changes.

Monday  12/9/2013 – checked on the results.  Kind of surprising.  At first it looked like the partitioned table was overall worse:

Summary of test results

               TEST_NAME TOTAL_ELAPSED_IN_SECONDS SELECTS_EXECUTED AVERAGE_ELAPSED_IN_SECONDS
    -------------------- ------------------------ ---------------- --------------------------
          SUBPARTITIONED                    21888             1097                         19
             PARTITIONED                    28741             1098                         26

The average elapsed time is 7 seconds worse for the partitioned table.  But, it looks like it is just one query that ran forever:

Select statements that ran 3 times faster with SUBPARTITIONED than with PARTITIONED.

T1=SUBPARTITIONED
T2=PARTITIONED

    SQLNUMBER T1_EXECUTE_PLAN_HASH T2_EXECUTE_PLAN_HASH T1_ELAPSED_IN_SECONDS T2_ELAPSED_IN_SECONDS
    --------- -------------------- -------------------- --------------------- ---------------------
            1            132181740           3487286224                     0                     1
           26            519522315           2715186677                     0                     1
           29            576765457            126877493                     0                     3
           42           1949964610           1017887051                     0                     1
           44           2612664434           2468569779                     0                     1
          125           3635909344           3120111659                     0                     1
          139           4142498169           1711377325                     0                     4
          142           1949964610           1017887051                     0                     3
          146           3988394307           3908049636                     0                     1
          168           2456608469           1734394656                     0                     1
          183           1992712897           1892184823                     0                     1
          194            730224497           3304174748                     0                     2
          210           2471705937            413083224                     0                     2
          212           1136809234           1249281329                     0                     1
          231           1136809234           3510866760                     0                     1
          240           2245807097           3237427885                     0                    38
          243           2008073743           3063672546                     0                     2
          250            171528240           2347117630                     0                     1
          253           3318237026           1642310238                     0                     2
          255            134409516           2506142998                     0                     2
          257           1592400063           3287183966                     1                    42
          267            214464307           2362685835                     0                    37
          280           3036674491            485416563                     0                     1
          281           2368396631           4191810915                     1                     4
          284           3032140904           4187103964                     1                     8
          285           2658113470           3977509591                     0                     2
          298           3569217931            667263099                     1                     8
          299           3452303321           1155893334                     0                     1
          339           3523597150            295969594                     0                     1
          403           1185652227           1913146698                     0                     1
          415           1970475271           2420243071                     0                     1
          422           4156965483            279313521                     0                     1
          425           3264016178            571714774                     0                     1
          446           1912229826           2886603256                     0                     3
          450           3114994453           2296118855                     0                     1
          452            990656627           1155893334                     0                     1
          487           3657518979           4017447622                     1                     4
          488           2245790501           3044059245                     1                     5
          492           3556434869           2777479666                     2                    13
          500           2791538642           3229791960                     0                     3
          507           1022324117           2850238236                     0                     1
          516            730224497           1323947471                     0                   144
          537           2812284467            954567070                     0                     1
          562           2430982563            960420868                     0                     1
          564            471884050           2240466682                     0                     1
          567           2082855664           3880360762                     0                     1
          575           1464032855            957824384                     0                     1
          580           3483521766           1301346464                     0                     3
          596            477286209           3908566847                     0                     1
          599           2115737620           1127244648                     0                     1
          618           2046795495           2263540886                     0                     2
          619           1999862643           3032897353                     0                     1
          624             80828603           3859873516                     0                     1
          645           2234456289           3298293583                     0                     1
          687           1869742304           1548224797                     2                     8
          690           1818714078            549393927                     0                     1
          693           3183101214           2747043384                     0                     1
          697             88047508           1694964884                     0                     1
          711           4269751641            890384010                     0                     1
          727           3452303321           1155893334                     0                     1
          739           3207535138           3771435509                     0                     1
          760            251196161           4273063876                     0                     1
          765           1492540013             28059524                     1                     4
          771           2458612738            899292907                     0                     3
          787            891484402             28400258                     0                   285
          788           2091206452           2721490179                    27                 20175
          789           1618107812           4237374652                     1                     6
          795           3452303321           1155893334                     0                     1
          800           3264016178            571714774                     0                     1
          831            192562403           4152761999                     0                     1
          833           1428715044           2108888259                     0                     2
          843            159432674           4045705765                     0                     6
          846             88047508           1694964884                     0                     1
          867           1783568484           1718969544                     0                     1
          875           1785252933           4287837615                     0                     1
          885            481357144           1125354053                     0                     1
          890            853060601            472723967                     0                     1
          894           1600013303           1756238559                     0                     1
          911           2893000376           1133722322                     0                     3
          920           2341487205           4058451115                     0                     1
          934           3334133472            476748915                     0                     1
          947           3167713409           4268663516                     0                     1
          964           2748476399             26022174                     0                     1
          970           3658693387            803766358                     0                     1
          974            806871272           3610447438                     0                     1
          978            481357144           1609991078                     0                     3
          986           3286938759            278568628                     0                     1
         1010           1329529970           2419262306                     0                     1
         1016           4043625178           4095884725                     0                     2
         1077            734703588           4131440272                     0                     2
         1079           3020497659           1562012967                     0                     2
         1081           1351379472           3751501791                     0                     1

Number of selects=92

So, select statement number 788 ran for 20175 seconds but the total run time for all the select statements on the partitioned table is 28741.  But on the subpartitioned table the total elapsed time was 21888.  So, this means that if you take out the one outlier the rest are better.  In fact 360 of the 1100 queries ran 3 times faster on the partitioned table:

Select statements that ran 3 times faster with PARTITIONED than with SUBPARTITIONED.

T1=PARTITIONED
T2=SUBPARTITIONED

    SQLNUMBER T1_EXECUTE_PLAN_HASH T2_EXECUTE_PLAN_HASH T1_ELAPSED_IN_SECONDS T2_ELAPSED_IN_SECONDS
    --------- -------------------- -------------------- --------------------- ---------------------
            5           4119227308            802119458                     0                     1
            7           2795778672           2722735984                     5                    92
            8           4222900571           1219059949                     0                     3
            9            605908923            149716553                     6                    97
           13           4141527877           4074139318                     5                    23
           14           2311007004           3710194989                     0                     2
           15            413083224            576765457                     0                     1
           18             63770943           4136831938                     1                    68
           20           3543913524           3432908518                     0                     2
           24            549393927           1818714078                     0                     1
           27            485416563           4262285519                     0                     1
           31           3122485526            905724397                     0                     1
           35           4119227308            802119458                     0                     1
           37           3009464053           3466422284                     4                    41
           38           3855412977           2011557246                     0                     2
           40            141466906            914505668                     0                     2
           41           1581450173           2648133919                     0                     2
           43           2212819228           1122107625                     0                     1
           47           4287837615           3560923679                     0                     2
           54           3537543859            485920547                     9                   164
           57            554951496           2907486190                     0                     2
           59           1190687098           2600118200                     1                     5
           60            785619833            318078169                     0                     1
           63            869700311           3246411685                     3                    17
           66           3870860191           2118000686                    10                    32
           67           1778738354           3111387503                     5                    23
           69           2460657665            171706249                     2                    16
           70            850886074           3511011843                     2                    14
           77           1136939318           1760312018                     2                     7
           78           3512779267           3419612024                     3                    60
           81           1377935503           1844656043                     0                     2
           82            940772920           2080816522                     0                     2
           84           2098451859           1503207437                     3                    21
           88            131678173           1136809234                     0                     1
           90           4222900571           2950556023                     0                     1
           96           3302277886           3833736335                     5                    93
           97           3302277886           3833736335                     6                    86
          103           3028140077            834663019                     2                     7
          104            818785072           2715404655                     0                     2
          107           2795778672           2722735984                     6                    93
          109            605908923            149716553                     5                    95
          113           4141527877           4074139318                     1                    19
          114           2311007004           3710194989                     0                     2
          118             63770943           4136831938                     2                    22
          120           3543913524           3432908518                     0                     2
          132           3020522529           1410447547                     0                     1
          135           4119227308            802119458                     0                     2
          137           3009464053           3466422284                     3                    56
          138           3855412977           2011557246                     0                     2
          140            141466906            914505668                     0                     2
          141           1581450173           2648133919                     0                     3
          144           2468569779           2612664434                     0                     2
          147           4287837615           3560923679                     0                     3
          154           3537543859            485920547                     7                   217
          157            554951496           2907486190                     0                     1
          163            869700311           3246411685                     2                    17
          167           1778738354           3111387503                     4                    21
          169           2460657665            171706249                     1                    18
          170            850886074           3511011843                     2                    14
          172           4204759768           1251027890                     0                     1
          178           3512779267           3419612024                     4                    56
          181           1377935503           1844656043                     0                     2
          182            940772920           2080816522                     0                     1
          184           2098451859           1503207437                     3                    21
          185            927547703           4274555718                     1                     4
          188            131678173           1136809234                     0                     2
          189            131678173           1136809234                     0                     1
          191            131678173           1136809234                     0                     1
          193           2295627892           1136809234                     3                    10
          196           3302277886           3833736335                     4                    86
          197           3302277886           3833736335                     7                    83
          206           2002609677           1455783262                     0                     1
          207           3304174748            730224497                     0                     1
          209           3477354767           1495831314                     0                     8
          211           1018982321           1281756587                     0                     1
          217           1796426939            153411509                     1                    55
          219           2697057286           2091206452                     0                     1
          226            172041826           3690902225                     0                     1
          232            621088165           4256853927                     0                     1
          234           4287837615            927299197                     0                     2
          238           3123422458           3720295907                     0                     1
          241           2773444272            214464307                     0                     1
          242           1279697186             94221410                     0                     1
          245           3848674134           1860979758                     2                    14
          246           1279697186             94221410                     0                     1
          251            301480002           1455783262                     2                    46
          259            674482781            958439138                     3                    16
          261           2993069276            175468268                     7                    22
          263           3743123262           1617853485                     1                    14
          264            921365118            777222318                     3                    46
          266             34792436           1954080369                     0                     1
          268           4229840264           2558257577                     3                    65
          270           1428007853           1580256307                     2                    18
          277           1615675145            233533669                     5                    31
          282           3592292604           1855471963                     0                     1
          288           2712441197           4172600861                     3                    31
          293           3512378671            818778709                     0                     1
          294           3221981558           2218040347                    10                    87
          297           3973750178            354935558                     0                     1
          300           3158597478           4031750948                    18                    99
          306           1224447999           2801823997                     4                    19
          309           1986090690            210732794                     3                    16
          310           3572367957           3643066087                     0                     3
          312            219268185            414619172                     2                   122
          315           2454869164           1853307727                     0                     3
          316           3164340055           3636639086                     0                     2
          317           3893310587            826612540                     0                     1
          330           4045705765           2604431171                     0                     1
          335           4141527877            203873600                     2                    19
          336           3330775813            355824657                    10                    39
          338           1783660597           1755496244                     7                    28
          340           3151250706            323502215                     0                     4
          345           2795778672            587030526                     4                    56
          348           1010781295           3495362923                     1                    15
          352           1372355995           4167521039                     3                     9
          359           3713092053           2347621269                     2                    16
          366            784242139           1230092054                     4                    18
          367            844759636           3002882513                     6                    25
          369           2978744550           1592400063                     3                    46
          370            548010671           1592400063                     4                    72
          372           2978744550           1592400063                     3                    46
          374           3205067923           1455783262                     1                    16
          375           2792192786           2458717189                     5                    22
          376           1431802826            363205584                     0                     1
          378           4146197756             80800755                    17                    54
          379           4137692180           2227304303                     5                    38
          381           1766155454           3379198769                     0                     3
          382           2344589579            348442591                     9                   102
          384           2664709183           3283214843                     4                    14
          385            548010671           1592400063                     1                    38
          388             35136272           2536670766                     1                    34
          390            791104872            121318690                     1                    26
          391            675783434           1248760078                     0                     1
          394             20069364           3567596641                     1                     4
          395           3107031055           2559547781                    35                   114
          396           1694964884             88047508                     0                     3
          397           2589426831           2225681245                    56                   223
          399           3672530325           4218766008                    12                    52
          401             81965553           3893129720                     6                    30
          404           2674938682            996387427                     0                     3
          407           2596137342            657169392                     0                     1
          409            641004368            242581192                     0                     1
          410           4116845036            120077130                     0                     3
          411           3028140077            834663019                     1                     4
          412            641004368            242581192                     0                     2
          413           3213788793           3965030257                     5                    41
          414           3252018468           4052438505                     2                    12
          417             35136272             89414102                     1                    13
          418            809554145           2818889590                     2                    11
          420           3635916442           1130017906                     3                    22
          424           3034853210           2742269090                     0                     3
          426            543701480            117767735                     3                    46
          427           2968716376           4184677691                    25                   127
          428           3352327659           1484853288                     2                    36
          430           1959343954           2961695063                     3                    19
          434           4287837615            927299197                     0                     2
          437            906699021           3109046727                     0                     3
          438           2449180949           1051156722                     1                    10
          439            482237569           2041588121                     4                    17
          441           4214669915           3694272479                    15                    73
          445           4069609026            597325785                     9                    42
          447           1133722322           2398738343                     2                    16
          448           2574645972           3984434946                    11                    39
          449           1374733338            963986994                     0                     2
          453           2613850249           1870432166                     0                     1
          454           3603280934           2469021761                     6                    21
          455           3181292112           3580289785                    11                    96
          456           2746714852           1170468436                    13                    55
          457           2948867885           2237065904                     8                    36
          461           1256206000           3662079612                     6                    23
          463           2157459676           3494674938                     8                    56
          465            703796412           1803464574                     2                    27
          466           2000634797           2339051617                     4                    55
          478           3805348377           2732968167                    61                   195
          479           2250730745           1175151710                    25                   105
          483           3902141807           4205516483                     1                     6
          490           1133722322           2893000376                     0                     3
          499             60985504           1900853982                     0                     1
          506           1133722322           2398738343                     1                    15
          508           3826428219           2498802965                     0                     1
          518            475365937           1013193100                     0                     1
          523           1308691500           3674247890                     0                     1
          525            444881803           3972715693                     0                     4
          529           1485324493            865981143                     0                     1
          534           1050643547           3967539854                    10                    32
          536           3743602179           2817850789                     0                     1
          538            528599785            192562403                     0                     1
          549            429431707           3211254462                     5                    19
          555            796711710           1954011377                     0                     1
          560           1200407648             97542380                     0                     2
          561           3594089354           1593705223                     1                    15
          576             60985504           2323209470                     0                     1
          579           4003339294           3065635396                    21                    66
          585           3802623306            138596480                     0                     1
          586           3989397980           3964876652                    12                    57
          588           3359936816           2817355668                    19                    83
          593           2002609677           2197912005                     0                     2
          594           3603280934           2469021761                     6                    26
          595           3567216225           1378104618                     6                    27
          597            457629807           3445363505                     6                    26
          602           3529018530            663093016                     5                    26
          603           2652553177           3429201733                     1                    14
          607            254246892           3711137502                     0                     1
          608           1023824709           4271466169                     5                    27
          610           1972552104           2513047998                     0                     1
          615           1765993466            632746505                     0                     1
          616           1717238085            227199227                    12                   101
          625           3677274861           2650110423                     4                    18
          626           2472167095           1877921643                     0                     3
          631           1033711577           1654003341                     0                     1
          632           1594843399           3978759030                     0                     1
          637           2098451859           1503207437                     4                    19
          638           1737463295           3919169749                    14                    42
          643           2681581430            124870100                     0                     1
          644           1197130816           3942425265                     2                    19
          648           3628861908            682620512                     8                   133
          659           2311007004           3710194989                     0                     2
          672           3304174748            730224497                     0                     1
          673             14850055            230384850                     4                    42
          674           1985284796           1416278473                     8                    27
          676             12853673           2170075453                     0                     1
          680           2621635740           3866233712                     0                     1
          682           1541189169           1842502015                     0                     2
          688           4240367789           4220671806                     0                     1
          692           1243917079            890117005                     1                     7
          694             83745429           1785917626                     0                     1
          695           1085242216            390938494                     0                     1
          700           1183676676           2043157637                     0                     2
          703           3095806119           4133847950                     0                     1
          704           2203606035           1881055016                     5                    16
          705           3543913524           3432908518                     0                     3
          710           2975883337           3000421798                     3                    23
          712           1554917309           2568604745                     0                     1
          715           1480964869           2936672713                     5                    39
          719           2990826169            628695790                     8                    25
          721            557420560           3584461583                     5                    32
          724           1626721134            897703670                     5                    86
          729           3145142340           4281470634                     0                     1
          731           1501182785           4058356442                     1                    31
          732           1363512371           2053866888                     2                    14
          745           4261153711            864043944                     4                    22
          746           3304174748           2558257577                     0                     1
          752            413083224           2456608469                     0                     1
          755            719859268            997212176                     2                    41
          758           1963857183           2575817048                     0                     2
          759           1445915046           2872190763                     0                     1
          763           2552501319           3152043970                     2                    32
          764            719859268            997212176                     3                    79
          766           3021248828           2245807097                     0                     2
          767           3745050950           3092229689                    25                   180
          768           1726777343             58273833                     1                    27
          769           1133374780           2363565649                     5                    27
          774            676375542           1074406218                     0                     1
          777           1541029643            380808465                     1                    22
          781           1541029643            380808465                     1                    45
          782           3308698252           2042899431                     2                   116
          784           2336370369           1678069002                     7                   141
          793           3306911100           2950556023                     1                     4
          798           1501846798           1239098218                     1                     4
          801           1327643071             89414102                     2                    27
          806           2709078226           2950556023                     3                   119
          808           4160531842           2385365150                     2                    65
          810            834784553            987287545                     0                     2
          812           1846399381           1238750098                     0                     5
          814           2836291050           3371745419                    27                   109
          821           3623816385           3107996074                     1                     4
          822            852796726           2950556023                    36                   128
          823           3639134257           2039851179                     0                     1
          825            277681890           3395698893                     0                     3
          828            636115716           3860805913                     6                   182
          837           3512378671            818778709                     0                     1
          839           4137692180           2227304303                     6                    26
          841           2550685239           1593792368                     0                     1
          845           3569239734           1496145129                     0                     1
          848           2691789658           2687003833                     6                    31
          854           2952196369           1773563000                     0                     1
          859           3127169011            526275443                     7                   112
          860           2673768194            952093521                     2                    92
          864           4131440272            734703588                     0                     1
          865           3318373275            653210239                    13                    51
          868           2193471660           1548678613                     0                     3
          874           3569239734           1496145129                     0                     1
          884           1659677904           1284148610                     3                    23
          886           1565966462           1063392491                     0                     2
          889           2795778672           2722735984                     2                    65
          898           2187385701           1524548753                     2                    28
          904           2978744550           1592400063                     3                    83
          905           2338267501           2539396272                     1                    27
          907           1205577665           1199385901                     0                     1
          909           3281648418           3279029067                     5                    81
          910           1867933558           3109046727                     0                     1
          913             35136272           2790567021                     0                    11
          914           3480206317            617965729                    12                    42
          917           4287837615           3560923679                     0                     2
          921           3310616935           2805949908                     6                    34
          922           1371562207           1529528990                     5                    18
          923            141466906            914505668                     0                     2
          925           2416811124           3074177270                     9                   111
          927           3164340055           3636639086                     0                     1
          928            515461275           1368881992                     0                    17
          929           1961857361           3175113053                     5                    91
          933            767986140           1251229057                    13                   132
          939           3426182023           2903768886                     2                     7
          942           2673768194            952093521                     1                    90
          945             34792436           1954080369                     0                     1
          946           1963857183           2575817048                     0                     1
          948           2692964632           1950113266                     1                     9
          952            444881803           2863620788                     3                    16
          954           1932669626           2644538268                    25                   137
          955           2829038210           3860805913                     2                    87
          956           1630970061            113003627                    18                    96
          957           3331310318           1951099093                    15                   429
          960           3873569580           2485903893                    14                    61
          961           1333943684            683646213                     2                    21
          963            906699021           3109046727                     0                     1
          965           2916113877           1178101678                     0                     1
          972           2580187424           3320833332                     0                     1
          975            278568628           4245439279                     0                     2
          979           4287837615            927299197                     0                     3
          983           1942138342           2415146388                     6                    61
          984           3946107053           2830341616                     6                    61
          985           3099061006            630428475                     0                     1
          987           3308698252           2042899431                     3                    46
          988            585068410           4210894888                     0                     1
          989           1581450173           1592869925                     0                     2
          996            704162093           3992162641                     3                    18
          997            171626870            514164987                     4                    19
          998           1748881193            849054197                     4                    21
         1001            750696398           3734524772                     6                    22
         1002           3194669797           1139843211                     0                     2
         1003           3529478430           1519530064                    22                   122
         1004           3545531920           1669321075                     2                    26
         1005           1639643261           4020212824                     1                    17
         1006           3470297531            401363160                     4                    21
         1007           3944484529           1766094719                     2                    21
         1008           2379317084           2726897252                     3                    64
         1026           3043957992           3066556786                     2                    16
         1027            154068323           2338372084                     5                    25
         1031            698355484           1860020790                    21                   146
         1038           1908651256            279317699                     5                    22
         1044           1827524969           3671333338                     8                    84
         1045           4083549983           3527586153                     7                    79
         1046           1380679740           2712456753                    13                    47
         1058           2026087040           1305282819                    14                    42
         1060           1929017231            710464237                     3                    17
         1061           4137692180           2227304303                     6                    19
         1062           1702457792           3772999177                     0                     1
         1064           2999193457            695687195                     0                     2
         1067           1684133672            891302388                     0                     1
         1073           3920929734           3557807400                     8                    38
         1076           3528983071            427663915                     2                    16
         1078           3231023868           3522985088                     4                    17
         1082            431020997           2495507135                     6                    18
         1083            525306902           1632729601                     0                     1
         1084            400243155           3017891299                     5                    43
         1090           4058409588            399171116                     0                     9
         1092           3957036512           4095144955                     3                    35
         1093           2781171125           3889721500                    24                   124
         1095           1260924822           1105517768                     0                     1
         1099           3068411137           1099896264                     3                    17

Number of selects=360

So, I will have to investigate the one query that took forever and maybe rerun the ones that showed the largest time difference.  I think this is a long enough post so I’ll follow-up with future posts on the results of my investigation.

– Bobby

Posted in Uncategorized | Leave a comment

Four Dimensions of DBA Activity

This week I am reviewing my accomplishments for 2013 and thinking of possible goals for 2014 in preparation for my annual performance review.  After reviewing my notes about what I did this year and brainstorming about what I want to do next year I thought of four categories to put the types of activity that I do as an Oracle Database Administrator.  Maybe sharing these will help someone else out or at least help me clarify for myself the type of things I need to do next year.

  1. Use the knowledge and tools I have
  2. Acquire new tools
  3. Share my knowledge with others
  4. Acquire new knowledge

Number 1 is just doing regular work like migrations, creating new databases, solving problems.  Sure, you might learn a little or make a little script here or there, but this is mainly just taking what you already have and applying it.

Number 2 means preparing for future work by getting new tools in place that will help you be more efficient.  This could be designing a script or scripts that you write yourself from scratch.  It could be downloading a free script or program.  It could be evaluating and purchasing a new program or online service.

Number 3 includes mentoring other DBA’s and developers, giving talks, making documentation – any kind of output of my existing Oracle database knowledge to make others more effective.

Number 4 refers to any kind of intake of new Oracle database knowledge.  Can be reading books, online articles, Oracle support notes, manuals.  Can also be research.  Research can include writing scripts but usually they are test scripts to prove that something is true and not reusable tools.

I guess you really can’t completely separate these four types of activity.  Often you have to stop working on something to build a little tool, or to read an article.  But, maybe it is helpful to break up the work in my mind into these four logical categories or dimensions of DBA activity.

– Bobby

P.S. I’m dropping a table with tens of thousands of subpartitions and it is taking forever.  So, that’s why I had time to write this post now.

P.P.S. Finally finished:

Table dropped.

Elapsed: 00:37:45.15
Posted in Uncategorized | 1 Comment

Good blog post – OK to be the DBA I am

This is a good blog post.  I’ve come back to it multiple times to get perspective on my career and involvement in the Oracle community:

Tim Hall blog post on why you shouldn’t try to become an Oracle ACE

I like it because it encourages me to embrace my own skills, personality, and desires as they are and not try to be someone I’m not.  It’s OK for me to be the DBA I am and not what someone else is or appears to be.

– Bobby

p.s. To those of you who celebrate the American holiday of Thanksgiving I wish you a happy holiday!

Posted in Uncategorized | Leave a comment

Default degree may cause performance problems

I encourage people that I work with to put a small number like 8 as the parallel degree when they want to create tables or indexes to use parallel query.  For example:

SQL> create table test parallel 8 as select * from dba_tables;

Table created.

SQL> 
SQL> select degree from user_tables where table_name='TEST';

DEGREE
----------
         8

But frequently I find tables that were created with the default degree by leaving out a number on the parallel clause:

SQL> create table test parallel as select * from dba_tables;

Table created.

SQL> 
SQL> select degree from user_tables where table_name='TEST';

DEGREE
----------
   DEFAULT

The problem is that on a large RAC system with a lot of CPUs per node the default degree can be a large number.  A table with a large degree can cause a single query to eat up all of the available parallel query processes.  That’s fine if only one query needs to run at a time but if you plan to run multiple queries in parallel you need to divide up the parallel query processes among them.  I.e. if you have 100 parallel query processes and need to run 10 queries at a time then you need to be sure each query only gets 10 of them.  I guess degree=5 is 10 processes but the point is that you don’t want to start running a bunch of queries with a degree of 50 each when you have 100 parallel processes to divide up.

With the default settings default degree is 2 X number of cpus X number of RAC nodes.  I tested this on an Exadata V2 with 2 nodes and 16 cpus per node.  The result was as expected, degree=64:

Final cost for query block SEL$1 (#0) - All Rows Plan:
  Best join order: 1
  Cost: 2.1370  Degree: 64  Card: 4203.0000  Bytes: 54639
  Resc: 123.0910  Resc_io: 123.0000  Resc_cpu: 2311650
  Resp: 2.1370  Resp_io: 2.1354  Resc_cpu: 40133

Just to verify that a query with parallel 8 would really use degree 8 I ran the same test with the same table but parallel 8:

Final cost for query block SEL$1 (#0) - All Rows Plan:
  Best join order: 1
  Cost: 6.5419  Degree: 8  Card: 4715.0000  Bytes: 61295
  Resc: 47.1020  Resc_io: 47.0000  Resc_cpu: 2593250
  Resp: 6.5419  Resp_io: 6.5278  Resc_cpu: 360174

Also note the lower cost(2) in the plan with default degree:

--------------------------------------------------+-----------------------------------+-------------------------+
| Id  | Operation                       | Name    | Rows  | Bytes | Cost  | Time      |  TQ  |IN-OUT|PQ Distrib |
--------------------------------------------------+-----------------------------------+-------------------------+
| 0   | SELECT STATEMENT                |         |       |       |     2 |           |      |      |           |
| 1   |  SORT AGGREGATE                 |         |     1 |    13 |       |           |      |      |           |
| 2   |   PX COORDINATOR                |         |       |       |       |           |      |      |           |
| 3   |    PX SEND QC (RANDOM)          | :TQ10000|     1 |    13 |       |           |:Q1000| P->S |QC (RANDOM)|
| 4   |     SORT AGGREGATE              |         |     1 |    13 |       |           |:Q1000| PCWP |           |
| 5   |      PX BLOCK ITERATOR          |         |  4203 |   53K |     2 |  00:00:01 |:Q1000| PCWC |           |
| 6   |       TABLE ACCESS STORAGE FULL | TEST    |  4203 |   53K |     2 |  00:00:01 |:Q1000| PCWP |           |
--------------------------------------------------+-----------------------------------+-------------------------+

Compared to degree 8 (cost=7):

--------------------------------------------------+-----------------------------------+-------------------------+
| Id  | Operation                       | Name    | Rows  | Bytes | Cost  | Time      |  TQ  |IN-OUT|PQ Distrib |
--------------------------------------------------+-----------------------------------+-------------------------+
| 0   | SELECT STATEMENT                |         |       |       |     7 |           |      |      |           |
| 1   |  SORT AGGREGATE                 |         |     1 |    13 |       |           |      |      |           |
| 2   |   PX COORDINATOR                |         |       |       |       |           |      |      |           |
| 3   |    PX SEND QC (RANDOM)          | :TQ10000|     1 |    13 |       |           |:Q1000| P->S |QC (RANDOM)|
| 4   |     SORT AGGREGATE              |         |     1 |    13 |       |           |:Q1000| PCWP |           |
| 5   |      PX BLOCK ITERATOR          |         |  4715 |   60K |     7 |  00:00:01 |:Q1000| PCWC |           |
| 6   |       TABLE ACCESS STORAGE FULL | TEST    |  4715 |   60K |     7 |  00:00:01 |:Q1000| PCWP |           |
--------------------------------------------------+-----------------------------------+-------------------------+

So, this shows that in this case with 2 node RAC and 16 cpus per node that the optimizer uses degree 64 for default degree and is more likely to choose a full scan over an index scan because the cost of the degree 64 full scan is less than that of a degree 8 full scan.

The key point is to understand that putting the keyword PARALLEL by itself on a table or index creation statement instead of PARALLEL 8 (or 4 or 16) can result in unexpectedly high degree.  This high degree can cause performance to degrade by allowing individual queries to eat up the parallel query processes leaving other queries to run inefficiently without the expected parallelism.  The high degree also reduces the cost of a full scan potentially causing them to be favored over index scans where the index scan would be more efficient.

– Bobby

p.s. Here is a zip of the scripts and logs that I used to create the 10053 traces: zip

Posted in Uncategorized | 2 Comments

How to find queries that use subpartition statistics

Yesterday I was trying to figure out if any queries on a particular production database were using subpartition statistics on a certain table.  We are having trouble getting the statistics gathering job to finish gathering stats on all the subpartitions of this table in the window of time we have given the stats job.  My thought was that we may not even need stats on the subpartitions, so I wanted to find queries that would prove me wrong.

My understanding of Oracle optimizer statistics is that there are three levels – table or global, partition, and subpartition.  The table I am working on is partitioned by range and subpartitioned by list.  So, I think that the levels are used in these conditions:

  1. Global or table: Range that crosses partition boundaries
  2. Partition: Range is within one partition but specifies more than one list value
  3. Subpartition: Range is within one partition and specifies one list value

In the table I was working on it was partitioned by week and subpartitioned by location so a query that specified a particular week and an individual location should use the subpartition stats.

So, I did some experimentation and came up with this query:

select
p.PLAN_HASH_VALUE,
min(p.sql_id),
count(*)
from 
DBA_HIST_SQL_PLAN p
where 
p.OBJECT_OWNER='MYOWNER' and
p.OBJECT_NAME='MYTABLE' and
p.partition_start=p.partition_stop and
substr(p.partition_start,1,1) 
in ('0','1','2','3','4','5','6','7','8','9') and
p.sql_id in (select sql_id from DBA_HIST_SQLSTAT)
group by p.PLAN_HASH_VALUE
order by p.PLAN_HASH_VALUE;

I’ve replaced the real owner and table name with MYOWNER and MYTABLE.  The point of this query is to find the distinct plans that use subpartition statistics and one sql query as an example of each plan.  There were multiple queries with the same plans but slightly different constants in their where clause so I just needed one example of each.

In my experimentation I found that plans that had the same numbers for the partition stop and start were the plans that used subpartition stats.  I’m not sure about the plans that don’t have numbers in their partition start and stop columns.

Here is what the output looks like:

PLAN_HASH_VALUE MIN(P.SQL_ID)   COUNT(*)
--------------- ------------- ----------
      151462653 fugdxj00cnwxt          1
      488358452 21kr79rst8663          2
      634063666 5fp4rnzgw6gvc          1
     1266515004 98zbx8gw95zf8          2
     1397966543 37gaxy58sr1np          2
     1468891601 5fp4rnzgw6gvc          1
     1681407819 001aysuwx1ba4        230
     1736890182 64tmnnap05m6b          2
     2242394890 2tp8jx3un534j          1
     2243586448 9fcd80ms6h7j4          2
     2418902214 64tmnnap05m6b          1
     2464907982 5fp4rnzgw6gvc          1
     3840767159 05u7fy79g0jgr        143
     4097240051 5mjgz2v8a3p6h          1

This is the output on our real system.  Once I got this list I built a script to dump out all of these plans and the one sql_id for each:

select * from table(DBMS_XPLAN.DISPLAY_AWR('fugdxj00cnwxt',151462653,NULL,'ALL'));
select * from table(DBMS_XPLAN.DISPLAY_AWR('21kr79rst8663',488358452,NULL,'ALL'));
select * from table(DBMS_XPLAN.DISPLAY_AWR('5fp4rnzgw6gvc',634063666,NULL,'ALL'));
select * from table(DBMS_XPLAN.DISPLAY_AWR('98zbx8gw95zf8',1266515004,NULL,'ALL'));
select * from table(DBMS_XPLAN.DISPLAY_AWR('37gaxy58sr1np',1397966543,NULL,'ALL'));
select * from table(DBMS_XPLAN.DISPLAY_AWR('5fp4rnzgw6gvc',1468891601,NULL,'ALL'));
select * from table(DBMS_XPLAN.DISPLAY_AWR('001aysuwx1ba4',1681407819,NULL,'ALL'));
select * from table(DBMS_XPLAN.DISPLAY_AWR('64tmnnap05m6b',1736890182,NULL,'ALL'));
select * from table(DBMS_XPLAN.DISPLAY_AWR('2tp8jx3un534j',2242394890,NULL,'ALL'));
select * from table(DBMS_XPLAN.DISPLAY_AWR('9fcd80ms6h7j4',2243586448,NULL,'ALL'));
select * from table(DBMS_XPLAN.DISPLAY_AWR('64tmnnap05m6b',2418902214,NULL,'ALL'));
select * from table(DBMS_XPLAN.DISPLAY_AWR('5fp4rnzgw6gvc',2464907982,NULL,'ALL'));
select * from table(DBMS_XPLAN.DISPLAY_AWR('05u7fy79g0jgr',3840767159,NULL,'ALL'));
select * from table(DBMS_XPLAN.DISPLAY_AWR('5mjgz2v8a3p6h',4097240051,NULL,'ALL'));

Here is a edited down output of just the relevant part of the first plan:

Plan hash value: 151462653

------------------------------------------------------------------
| Id  | Operation                 | Name         | Pstart| Pstop |
------------------------------------------------------------------
|  31 | TABLE ACCESS STORAGE FULL | MYTABLE      | 41017 | 41017 |
------------------------------------------------------------------

This query had conditions in its where clause like this:

LIST_COLUMN = 1234 AND
(RANGE_COLUMN BETWEEN
TO_DATE('20130609000000','YYYYMMDDHH24MISS') AND
TO_DATE('20130615000000','YYYYMMDDHH24MISS'))

I’ve renamed the real column for the list subpartioning to LIST_COLUMN and renamed the real column for the range partitioning to RANGE_COLUMN.

One interesting thing I realized was that since we are on an Exadata system and there are no visible indexes on the subpartitioned table the subpartition stats aren’t being used to determine whether the query will use an index scan or full scan.  But, they are used in these queries to determine the number of rows the full scan will return so that could impact the plan.

I’m thinking of using table preferences to just turn off the subpartition stats gathering using a call like this:

begin

DBMS_STATS.SET_TABLE_PREFS ('MYOWNER','MYTABLE',
    pname=>'GRANULARITY',
    pvalue=>'GLOBAL AND PARTITION');

end;
/

As it is the table has 40,000 subpartitions and the daily stats job isn’t finishing anyway so regardless of the queries that use the subpartition stats I think we should set the preference.  Maybe just leave dynamic sampling to handle the queries that actually use the one subpartition’s stats or have some application job gather stats on the one subpartition when it is initially loaded.  It is a work in progress, but I thought I would share what I’ve been doing.

– Bobby

Posted in Uncategorized | Leave a comment

CPU Queue Time as SQL*Net wait

I was testing a script that did a lot of very short SQL statements and running many of them at the same time to bog down the CPU on the database server.  I kept seeing high “SQL*Net message from client” waits from my profiling SQL code.

Normally a profile of a single long running statement when there is a large CPU queue looks like this:

SUBSTR(TIMESOURCE,1,30)           SECONDS PERCENTAGE
------------------------------ ---------- ----------
TOTAL_TIME                             74        100
UNACCOUNTED_TIME                       37         50
CPU                                    37         50

This is a one CPU VM with two 100% CPU queries.  Each one’s CPU accounts for half of the total elapsed time leaving the other half unaccounted for.

But, take a high CPU load system and run a bunch of short sql statements the profile looks like this:

SUBSTR(TIMESOURCE,1,30)           SECONDS PERCENTAGE
------------------------------ ---------- ----------
TOTAL_TIME                             13        100
SQL*Net message from client             8         62
log file sync                           5         38
CPU                                     1          8

This is a script with a bunch of insert/commit combinations like this:

insert into testtable values (1);
commit;
insert into testtable values (1);
commit;
insert into testtable values (1);
commit;
insert into testtable values (1);
commit;
insert into testtable values (1);
commit;
insert into testtable values (1);
commit;
insert into testtable values (1);
commit;
insert into testtable values (1);
commit;

Without the high CPU load the profile is like this:

SUBSTR(TIMESOURCE,1,30)           SECONDS PERCENTAGE
------------------------------ ---------- ----------
TOTAL_TIME                              3        100
SQL*Net message from client             1         33
CPU                                     1         33
log file sync                           1         33

It looks like the SQL*Net message from client and log file sync times were both inflated by the high CPU load in the previous profile.

I tried this for shared and dedicated servers and for some reason shared servers reports even more SQL*Net waits for the same CPU load:

SUBSTR(TIMESOURCE,1,30)           SECONDS PERCENTAGE
------------------------------ ---------- ----------
TOTAL_TIME                             20        100
SQL*Net message from client            14         70
log file sync                           6         30
CPU                                     1          5

In further testing I was getting twice as many SQL*Net message from client waits for the same script with shared servers compared to dedicated so maybe that is why shared server connections are more sensitive to high CPU loads and report higher SQL*Net message from client waits.

Here is what the CPU looked like for the shared server example:

top-c

Notice the six loops – a simple C program with infinite loop.  These should be starving the other oracle processes for the CPU.  Note that this is the “c” option of top which is really helpful because it shows you the oracle process names like ora_lgwr_orcl similar to the default display on HP-UX’s glance tool.

So, I guess I was surprised that SQL*Net message from client waits were inflated by queuing on the CPU but it looks like they are.  This appears to be most visible when you have a lot of short run time SQL statements.

– Bobby

 

Posted in Uncategorized | 2 Comments

Session profile using V$ tables

Hopefully this is not too redundant to previous posts but I’ve found that I keep using a particular script to debug performance issues and I thought I’d share it and explain what I use it for.  It’s helpful to me so I’m sure someone could use it unless they have their own tools which meet the same needs.

The first usergroup presentation I did was on the topic of profiles and was based on things I had learned a variety of places including Jeff Holt and Cary Millsap’s excellent book titled “Optimizing Oracle Performance”.

Out of all that came a simple set of SQL and sqlplus commands that I tag on to the end of a sqlplus script that I want to get a profile of.  In my case a profile includes:

  • Real Elapsed time
  • CPU
  • Waits

The main point of my paper and the critical point I got from the Holt and Millsap book and other things was to compare the total waits and CPU to the real time.  So, this SQL/sqlplus code is a quick and dirty way to get this kind of profile for a sqlplus script that you are running as part of a performance testing exercise.  Here is the code:

VARIABLE monitored_sid number;

begin

SELECT sid into :monitored_sid from v$session 
where audsid=USERENV('SESSIONID');

end;
/

SELECT SID, substr(USERNAME,1,12) Username, 
substr(TIMESOURCE,1,30), SECONDS, 
ROUND(SECONDS/(SELECT ROUND((SYSDATE-LOGON_TIME)*24*60*60,0) 
FROM V$SESSION WHERE SID= :monitored_sid),2)*100 
AS PERCENTAGE
FROM
(SELECT logon_time, SID, username, 'TOTAL_TIME' TIMESOURCE,
ROUND((SYSDATE-LOGON_TIME)*24*60*60,0) SECONDS
FROM V$SESSION 
WHERE SID= :monitored_sid
UNION ALL
SELECT a.logon_time, a.SID,a.USERNAME,'CPU' TIMESOURCE,
ROUND((VALUE/100),0) SECONDS
FROM V$SESSION a, V$SESSTAT b
where a.SID = b.SID
and a.SID = :monitored_sid
and b.STATISTIC# = (SELECT STATISTIC# FROM V$STATNAME 
WHERE NAME='CPU used by this session')
UNION ALL
SELECT b.logon_time, a.SID,b.USERNAME,a.EVENT TIMESOURCE,
ROUND((TIME_WAITED/100),0) SECONDS
FROM V$SESSION_EVENT a, V$SESSION b
WHERE a.SID = b.SID
AND a.SID= :monitored_sid
UNION ALL
select b.logon_time, a.sid, b.username, 
'UNACCOUNTED_TIME' TIMESOURCE,
ROUND(MAX(SYSDATE-LOGON_TIME)*24*60*60,0)-
(ROUND(SUM((TIME_WAITED/100)),0)+ROUND(MAX(VALUE/100),0)) 
as UNACCOUNTED_FOR_TIME
FROM V$SESSION_EVENT a, V$SESSION b, V$SESSTAT c
WHERE a.SID = b.SID
AND b.sid = c.sid
and c.STATISTIC# = (SELECT STATISTIC# FROM V$STATNAME 
WHERE NAME='CPU used by this session')
AND a.SID= :monitored_sid
group by b.logon_time, a.sid, b.username)
order by SECONDS desc;

And here is some typical output:

SUBSTR(TIMESOURCE,1,30)           SECONDS PERCENTAGE
------------------------------ ---------- ----------
TOTAL_TIME                             43        100
direct path read                       30         70
CPU                                     5         12
db file scattered read                  4          9
db file sequential read                 4          9
Disk file operations I/O                0          0
SQL*Net message to client               0          0
SQL*Net message from client             0          0
events in waitclass Other               0          0
enq: KO - fast object checkpoi          0          0
UNACCOUNTED_TIME                       -1         -2

I left off the initial SID and username columns so the output would fit on this page, but if you run it you get that information as well.  The output contains waits and CPU which I think are typical but the two values TOTAL_TIME and UNACCOUNTED_TIME may be unusual.

TOTAL_TIME is the real elapsed time since the user first logged in to this session.

UNACCOUNTED_TIME is TOTAL_TIME-sum of the waits and CPU.  If there is a lot of queuing for the CPU then UNACCOUNTED_TIME goes up.

Here is a zip of an example of the use of this code in a script.

The idea is that you run the script like this:

username/password@dbname < profileexample.sql

If you want to learn how to use this kind of profile I would encourage you to read the paper, but the short answer is to just look at which is the biggest consumer of time – CPU, a particular wait, or something unknown, and let that lead the next steps of your investigation.

– Bobby

Posted in Uncategorized | Leave a comment

Same plan hash value different partition range

Today I saw two different plans with the same plan hash value but different numbers of partitions.  So, the partition numbers must not factor into the plan hash value.  So, you can’t count on the plan hash value to fully indicate whether two plans are the same.

I’ve taken the real plans and just modified the table and index names so I won’t expose our real names.  But, otherwise this is the real thing:

10/30/2013 plan

Plan hash value: 11498413

----------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                               | Name              | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |    TQ  |IN-OUT| PQ Distrib |
----------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | MERGE STATEMENT                         |                   |       |       |  4440 (100)|          |       |       |        |      |            |
|   1 |  MERGE                                  | TABLE_ONE         |       |       |            |          |       |       |        |      |            |
|   2 |   PX COORDINATOR                        |                   |       |       |            |          |       |       |        |      |            |
|   3 |    PX SEND QC (RANDOM)                  | :TQ10000          | 21446 |    45M|  4440   (1)| 00:01:03 |       |       |  Q1,00 | P->S | QC (RAND)  |
|   4 |     VIEW                                |                   |       |       |            |          |       |       |  Q1,00 | PCWP |            |
|   5 |      NESTED LOOPS OUTER                 |                   | 21446 |    45M|  4440   (1)| 00:01:03 |       |       |  Q1,00 | PCWP |            |
|   6 |       PX PARTITION RANGE ALL            |                   | 21446 |    22M|  1459   (1)| 00:00:21 |     1 |   156 |  Q1,00 | PCWC |            |
|   7 |        TABLE ACCESS BY LOCAL INDEX ROWID| TABLE_TWO         | 21446 |    22M|  1459   (1)| 00:00:21 |     1 |   156 |  Q1,00 | PCWP |            |
|   8 |         INDEX RANGE SCAN                | INDEX_TABLE_TWO   | 21593 |       |    26   (0)| 00:00:01 |     1 |   156 |  Q1,00 | PCWP |            |
|   9 |       TABLE ACCESS BY GLOBAL INDEX ROWID| TABLE_ONE         |     1 |  1145 |     0   (0)|          | ROWID | ROWID |  Q1,00 | PCWP |            |
|  10 |        INDEX UNIQUE SCAN                | PK_TABLE_ONE      |     1 |       |     0   (0)|          |       |       |  Q1,00 | PCWP |            |
----------------------------------------------------------------------------------------------------------------------------------------------------------

11/11/2013 plan

Plan hash value: 11498413

----------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                               | Name              | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |    TQ  |IN-OUT| PQ Distrib |
----------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | MERGE STATEMENT                         |                   |       |       |  4845 (100)|          |       |       |        |      |            |
|   1 |  MERGE                                  | TABLE_ONE         |       |       |            |          |       |       |        |      |            |
|   2 |   PX COORDINATOR                        |                   |       |       |            |          |       |       |        |      |            |
|   3 |    PX SEND QC (RANDOM)                  | :TQ10000          | 21966 |    46M|  4845   (1)| 00:01:08 |       |       |  Q1,00 | P->S | QC (RAND)  |
|   4 |     VIEW                                |                   |       |       |            |          |       |       |  Q1,00 | PCWP |            |
|   5 |      NESTED LOOPS OUTER                 |                   | 21966 |    46M|  4845   (1)| 00:01:08 |       |       |  Q1,00 | PCWP |            |
|   6 |       PX PARTITION RANGE ALL            |                   | 21966 |    22M|  1469   (1)| 00:00:21 |     1 |   208 |  Q1,00 | PCWC |            |
|   7 |        TABLE ACCESS BY LOCAL INDEX ROWID| TABLE_TWO         | 21966 |    22M|  1469   (1)| 00:00:21 |     1 |   208 |  Q1,00 | PCWP |            |
|   8 |         INDEX RANGE SCAN                | INDEX_TABLE_TWO   | 22638 |       |    33   (0)| 00:00:01 |     1 |   208 |  Q1,00 | PCWP |            |
|   9 |       TABLE ACCESS BY GLOBAL INDEX ROWID| TABLE_ONE         |     1 |  1151 |     0   (0)|          | ROWID | ROWID |  Q1,00 | PCWP |            |
|  10 |        INDEX UNIQUE SCAN                | PK_TABLE_ONE      |     1 |       |     0   (0)|          |       |       |  Q1,00 | PCWP |            |
----------------------------------------------------------------------------------------------------------------------------------------------------------

One of these queries was run on 10/30/2013 (the one with fewer partitions).  The other was run yesterday and is still running.  Looks like the range scan has a bunch more partitions worth of data today and that is why the query, despite the same plan hash value, is running longer.

The Pstop column has the high partition number so it looks like we had 156 partitions on 10/30 and 208 yesterday unless I’m missing something.

– Bobby

Posted in Uncategorized | 5 Comments

Nethack install on Oracle Enterprise Linux 32 bit

So,  I play one computer game – Nethack.  I have a page on the blog if you want some information about it.  I just finished building a 32 bit Linux virtual machine running on VMware player for the purpose of compiling Nethack.  I used the latest version of Oracle Enterprise Linux and configured it as a software development workstation.

I did this because I wanted to be able to putty into the VM and have the screen look the same as it does when I putty into nethack.alt.org.  I got my putty settings working well now with I think IBM graphics for the symbols.  But, it is helpful to compile your own copy of the game when you want to figure out how something works.  Plus it is fun to dork around with C code every once and a while since my normal job hardly ever requires it.

I used to use Cygwin to compile my own copy and ran it on a CRT monitor on Windows XP as a DOS window.  This was the most like the character based terminals that nethack originally ran on when I played it in college.  But, now I have a nice 22 inch flat screen monitor at home and I’ve upgraded to Windows 7 which doesn’t have the DOS window anymore.  So, I’ve moved to putty as my method of choice for playing Nethack.

I had downloaded the 64 bit version of OEL to use to install Oracle 12c and 11.2.0.3 in virtual machines that I could run from my new 64 bit OS laptop.  So, my first choice for a Nethack VM was a 64 bit Linux VM.  I was thinking I would use it for both playing with Nethack and other development type tasks where Linux was helpful.  But, I was getting grief from the 64 bit environment.  Evidently the Nethack code has some places that convert unsigned integers into pointers and vice-versa.  On 64-bit OEL these variables are different lengths.  So, after messing with this for longer than I intended – all I’m trying to do is get it where I can run the games from putty – I gave up on 64-bit Linux.

But, the question was, does Oracle still have 32-bit Linux because the new 12c download was only on 64-bit – at least the last time I checked.  Sure enough, Oracle still supports 32 bit Linux and so I downloaded that version and it worked pretty much the same as the 64 bit install except that the Nethack code compiled without all the pointer to integer conversion warnings.

So, I have a 32 bit Nethack VM and two 64 bit Oracle database VMs.  Fun!

– Bobby

 

 

Posted in Uncategorized | Leave a comment

More work on parse time bug

I wasn’t sure if people would find a post on a bug that interesting.  If you don’t have the same bug I’m not sure what you would get out of it.  But, it is what I’m working on.

Here are my earlier rants on the same problem: 9b4m3fr3vf9kn and an4593dzvqr4v, SQLT Data Explosion.

So, I worked with Oracle support and they became convinced we were hitting this base bug:

16864042: KKPOSAGEPROPSCBK() MAY CAUSE UNNECESSARY EXADATA PERFORMANCE REGRESSION

It made sense to me because this was the base bug for another bug:

Bug 16694856 : EXADATA: SUBPARTITION WITH ‘LIBRARY CACHE LOCK’ ON RAC + INDEX OPERATION

16694856 has similar symptoms to what we have in production namely a lot of 9b4m3fr3vf9kn and an4593dzvqr4v internal query executions.  Anyway, Oracle development looked at the information I uploaded and concluded we had indeed hit bug 16864042 and produced a back ported patch for our release which is great.

So, I’ve applied the patch on dev and qa but I can’t reproduce the problem anywhere but prod so I won’t really know if the patch helps until it goes all the way through.  I built this script as a test of the bug:

drop table executions_before;

create table executions_before as 
select sum(executions) before_executions from v$sql where
sql_id = 'an4593dzvqr4v';

explain plan for select count(*) from OURPROBLEMTABLE;

select after_executions-before_executions
from 
(select sum(executions) after_executions
from v$sql where
sql_id = 'an4593dzvqr4v'),executions_before;

On dev and qa before and after the patch it produces the same results.  It returns a value > 0 once and then afterwards looks like this every time it is run:

AFTER_EXECUTIONS-BEFORE_EXECUTIONS
----------------------------------
                                 0

But on prod every time it is run it returns a value > 0:

AFTER_EXECUTIONS-BEFORE_EXECUTIONS
----------------------------------
                              1224

So, I’m hoping that after I apply the patch prod will start behaving like dev and qa and it will start returning 0 after the first run like in dev and qa.  At least that would be a quick test of the prod patch once it is in.

Anyway, just thought I would share my pain.  Not sure what to get out of this except that you can’t always duplicate a bug you are seeing on prod on a dev/test system.

– Bobby

 
Posted in Uncategorized | Leave a comment