Vishal desai’s Oracle Blog

April 24, 2015

Wait Chain analysis using Tanel’s awesome ash_wait_chains script

Filed under: Oracle Database, Troubleshooting — Tags: — vishaldesai @ 7:14 pm

Our database performance engineering team was trying to troubleshoot high wait time on enq:SQ – contention and was working with Oracle support. Snippet from Active Sessions and AWR report is shown below:

 

image

image

image

I thought it could be classic case of Sequence concurrency in RAC environment. I started looking as dba_hist_active_sess_history and found all the sessions were waiting on same sequence object id (p2=362). Object id 362 belongs to sequence AUDSES$ which is used by AUD$ and sequence cache size was already set to 10000. In previous releases there were couple of bugs where sequence cache for AUDSES$ was not high enough and workaround was to fix cache size but this particular database is on 11.2.0.4 and cache size is also 10000 so there was no reason to believe we were hitting those bugs.

image

I manually started mining ASH for sample session that led me all the way from one instance to another instance’s lgwr session.

image

image

image

image

So for given session 1286 and few others wait chain was as follows:

image

Then I realized, instead of doing this manually, I could use Tanel’s ash_wait_chains.sql to see the overall impact. As you can see from top of the output that more than 70% of impact was along the same line.

 

@dash_wait_chains username||':'||event  1=1 1596 1596

%This     SECONDS WAIT_CHAIN
------ ---------- ----------------------------------------------------------------------------------------------------------------------------------------------------
  70%   105023520 -> SYS:enq: SQ - contention -> SYS:row cache lock -> SYS:log file switch (archiving needed) -> SYS:control file sequential read
   9%    13698720 -> SYS:enq: SQ - contention -> SYS:row cache lock -> SYS:log file switch (archiving needed) -> SYS:Disk file Mirror Read
   6%     9803520 -> SYS:enq: SQ - contention -> SYS:log file switch (archiving needed) -> SYS:control file sequential read
   6%     9132480 -> SYS:enq: SQ - contention -> SYS:row cache lock -> SYS:log file switch (archiving needed) -> SYS:
   3%     4566240 -> SYS:enq: SQ - contention -> SYS:row cache lock -> SYS:log file switch (archiving needed) -> SYS:enq: CF - contention
   1%     1887840 -> SYS:buffer busy waits -> SYS:log file switch (archiving needed) -> SYS:control file sequential read
   1%     1278720 -> SYS:enq: SQ - contention -> SYS:log file switch (archiving needed) -> SYS:Disk file Mirror Read
   1%     1159430 -> DBFS_dbname01:buffer busy waits -> DBFS_dbname01:log file switch (archiving needed) -> SYS:control file sequential read
   1%      852480 -> SYS:enq: SQ - contention -> SYS:log file switch (archiving needed) -> SYS:
   0%      695520 -> DBSNMP:buffer busy waits -> ETL_USER:log file switch (archiving needed) -> SYS:control file sequential read
   0%      695520 -> SYS:row cache lock -> SYS:log file switch (archiving needed) -> SYS:control file sequential read
   0%      426240 -> SYS:enq: SQ - contention -> SYS:log file switch (archiving needed) -> SYS:enq: CF - contention
   0%      246240 -> SYS:buffer busy waits -> SYS:log file switch (archiving needed) -> SYS:Disk file Mirror Read
   0%      195500 -> SYS:log file switch (archiving needed) -> SYS:control file sequential read
   0%      182160 -> ETL_USER:log file switch (archiving needed) -> SYS:control file sequential read
   0%      164160 -> SYS:buffer busy waits -> SYS:log file switch (archiving needed) -> SYS:
   0%      151230 -> DBFS_dbname01:buffer busy waits -> DBFS_dbname01:log file switch (archiving needed) -> SYS:Disk file Mirror Read
   0%      100820 -> DBFS_dbname01:buffer busy waits -> DBFS_dbname01:log file switch (archiving needed) -> SYS:
   0%       90720 -> SYS:row cache lock -> SYS:log file switch (archiving needed) -> SYS:Disk file Mirror Read
   0%       90720 -> DBSNMP:buffer busy waits -> ETL_USER:log file switch (archiving needed) -> SYS:Disk file Mirror Read
   0%       82080 -> SYS:buffer busy waits -> SYS:log file switch (archiving needed) -> SYS:enq: CF - contention
   0%       60480 -> SYS:row cache lock -> SYS:log file switch (archiving needed) -> SYS:
   0%       60480 -> DBSNMP:buffer busy waits -> ETL_USER:log file switch (archiving needed) -> SYS:
   0%       50410 -> DBFS_dbname01:buffer busy waits -> DBFS_dbname01:log file switch (archiving needed) -> SYS:enq: CF - contention
   0%       32660 -> DBFS_dbname01:log file switch (archiving needed) -> SYS:control file sequential read
   0%       30240 -> SYS:row cache lock -> SYS:log file switch (archiving needed) -> SYS:enq: CF - contention
   0%       30240 -> DBSNMP:buffer busy waits -> ETL_USER:log file switch (archiving needed) -> SYS:enq: CF - contention
   0%       25500 -> SYS:log file switch (archiving needed) -> SYS:Disk file Mirror Read
   0%       23760 -> ETL_USER:log file switch (archiving needed) -> SYS:Disk file Mirror Read
   0%       17000 -> SYS:log file switch (archiving needed) -> SYS:
   0%       15840 -> ETL_USER:log file switch (archiving needed) -> SYS:
   0%       13590 -> SYS:enq: SQ - contention -> ETL_USER:
   0%        8500 -> SYS:log file switch (archiving needed) -> SYS:enq: CF - contention
   0%        7920 -> ETL_USER:log file switch (archiving needed) -> SYS:enq: CF - contention
   0%        5520 -> DBSNMP:log file switch (archiving needed) -> SYS:control file sequential read
   0%        4260 -> DBFS_dbname01:log file switch (archiving needed) -> SYS:Disk file Mirror Read
   0%        3600 -> ETL_USER:
   0%        3020 -> SYS:enq: SQ - contention -> ETL_USER:cell single block physical read
   0%        2840 -> DBFS_dbname01:log file switch (archiving needed) -> SYS:
   0%        1420 -> DBFS_dbname01:log file switch (archiving needed) -> SYS:enq: CF - contention
   0%         970 -> SYS:
   0%         870 -> GGADMIN:SQL*Net more data from client
   0%         720 -> DBSNMP:log file switch (archiving needed) -> SYS:Disk file Mirror Read
   0%         600 -> ETL_USER:cell single block physical read
   0%         480 -> DBSNMP:log file switch (archiving needed) -> SYS:
   0%         240 -> DBSNMP:log file switch (archiving needed) -> SYS:enq: CF - contention
   0%         230 -> SYS:control file sequential read
   0%         160 -> SYS:gc current request
   0%          90 -> SYS:flashback log file write
   0%          90 -> SYS:db file parallel write
   0%          80 -> ETL_USER:log file sync -> SYS:
   0%          80 -> ETL_USER:log file sync -> SYS:log file parallel write
   0%          80 -> GGADMIN:cell single block physical read
   0%          80 -> GGADMIN:
   0%          70 -> SYS:reliable message
   0%          70 -> SYS:log file sequential read
   0%          70 -> SYS:JS kgl get object wait
   0%          60 -> ETL_USER:resmgr:cpu quantum
   0%          40 -> SYS:log file parallel write
   0%          40 -> ETL_USER:cell multiblock physical read
   0%          30 -> SYS:ges lms sync during dynamic remastering and reconfig -> SYS:
   0%          30 -> GGADMIN:gcs drm freeze in enter server mode -> SYS:ges lms sync during dynamic remastering and reconfig -> SYS:
   0%          30 -> SYS:Disk file Mirror Read
   0%          20 -> SYS:enq: CF - contention
   0%          20 -> GGADMIN:Streams miscellaneous event
   0%          10 -> ETL_USER:direct path write temp
   0%          10 -> ETL_USER:gc cr grant 2-way
   0%          10 -> DBSNMP:log file sync -> SYS:log file parallel write
   0%          10 -> SYS:change tracking file synchronous read
   0%          10 -> U002585:
   0%          10 -> ETL_USER:direct path read temp
   0%          10 -> SYS:library cache lock
   0%          10 -> DBFS_dbname01:
   0%          10 -> ETL_USER:enq: FB - contention
   0%          10 -> ETL_USER:gc current block 3-way
   0%          10 -> ETL_USER:gc current block 2-way
   0%          10 -> SYS:ASM file metadata operation
   0%          10 -> DBFS_dbname01:direct path write
   0%          10 -> DBSNMP:log file sync -> SYS:

79 rows selected.

Further from below output its also clear that the ultimate blocker was session id 1262 on instance 2 (LGWR process). Line id with 3% impact matches my manual analysis.

 

dash_wait_chains instance_number||':'||session_id  1=1 1596 1596

%This     SECONDS WAIT_CHAIN
------ ---------- -----------------------------------------------------
  24%    35955360 -> 1:3164 -> 1:654 -> 2:2540 -> 2:1262
  21%    32447520 -> 1:2533 -> 1:654 -> 2:2540 -> 2:1262
  17%    25431840 -> 1:1914 -> 1:654 -> 2:2540 -> 2:1262
  13%    19293120 -> 1:1913 -> 1:654 -> 2:2540 -> 2:1262
  10%    14908320 -> 1:6 -> 1:654 -> 2:2540 -> 2:1262
   3%     4384800 -> 1:1286 -> 1:654 -> 2:2540 -> 2:1262
   1%     1503360 -> 2:2542 -> 2:2540 -> 2:1262
   1%     1503360 -> 2:1276 -> 2:2540 -> 2:1262
   1%     1503360 -> 2:2520 -> 2:2538 -> 2:1262
   1%     1503360 -> 2:1907 -> 2:2540 -> 2:1262
   1%     1503360 -> 2:3170 -> 2:2540 -> 2:1262
   1%     1503360 -> 2:2533 -> 2:2540 -> 2:1262
   1%     1503360 -> 2:1282 -> 2:2540 -> 2:1262
   1%     1503360 -> 2:25 -> 2:2540 -> 2:1262
   1%     1503360 -> 2:3171 -> 2:2540 -> 2:1262
   1%     1461890 -> 2:1906 -> 2:1909 -> 2:1262
   1%      876960 -> 1:654 -> 2:2540 -> 2:1262
   1%      876960 -> 2:1263 -> 2:2538 -> 2:1262
   0%      709920 -> 2:650 -> 2:3169 -> 2:1262
   0%      229680 -> 2:650 -> 2:2540 -> 2:1262
   0%      167040 -> 2:645 -> 2:3169 -> 2:1262
   0%      104400 -> 2:3163 -> 2:2540 -> 2:1262
   0%       20880 -> 2:653 -> 2:1262
   0%       20880 -> 2:1908 -> 2:1262
   0%       20880 -> 2:20 -> 2:1262
   0%       20880 -> 2:2540 -> 2:1262
   0%       20880 -> 2:1281 -> 2:1262
   0%       20880 -> 2:1269 -> 2:1262
   0%       20880 -> 2:2536 -> 2:1262
   0%       20880 -> 2:649 -> 2:1262
   0%       20880 -> 2:6 -> 2:1262
   0%       20880 -> 2:3169 -> 2:1262
   0%       20880 -> 2:1284 -> 2:1262
   0%       20880 -> 2:1896 -> 2:1262
   0%       20880 -> 2:2538 -> 2:1262
   0%       20880 -> 2:17 -> 2:1262
   0%       20880 -> 2:655 -> 2:1262
   0%       20880 -> 2:1280 -> 2:1262
   0%       20880 -> 2:1895 -> 2:1262
   0%       20880 -> 2:1899 -> 2:1262
   0%       20880 -> 2:3158 -> 2:1262
   0%       20880 -> 2:3167 -> 2:1262
   0%       20880 -> 2:24 -> 2:1262
   0%       20880 -> 2:1288 -> 2:1262
   0%       20590 -> 2:1909 -> 2:1262
   0%       20590 -> 2:2541 -> 2:1262
   0%       16820 -> 2:1913 -> 2:1262
   0%        6960 -> 2:2523 -> 2:1262
   0%        4510 -> 1:3164 -> 1:654
   0%        4070 -> 1:2533 -> 1:654
   0%        3190 -> 1:1914 -> 1:654
   0%        2420 -> 1:1913 -> 1:654
   0%        1870 -> 1:6 -> 1:654
   0%         880 -> 3:3162
   0%         720 -> 2:632

Now the question is what was LGWR process doing and why was it constantly trying to read control file. If you run 10046 on LGWR process you will notice that LGWR will read control file while doing log switches.

WAIT #0: nam='control file sequential read' ela= 59 file#=0 block#=1 blocks=1 obj#=-1 tim=1429886768732384
WAIT #0: nam='control file sequential read' ela= 203 file#=0 block#=40 blocks=1 obj#=-1 tim=142988668732612
WAIT #0: nam='control file sequential read' ela= 197 file#=0 block#=42 blocks=1 obj#=-1 tim=1429886768732845
WAIT #0: nam='control file sequential read' ela= 216 file#=0 block#=1 blocks=1 obj#=-1 tim=1429886768733206
WAIT #0: nam='control file sequential read' ela= 192 file#=1 block#=1 blocks=1 obj#=-1 tim=1429886768733440
WAIT #0: nam='control file sequential read' ela= 200 file#=0 block#=40 blocks=1 obj#=-1 tim=1429886768733674
WAIT #0: nam='control file sequential read' ela= 198 file#=0 block#=42 blocks=1 obj#=-1 tim=1429886768733909

Then I checked alert log on instance 2 and found number of occurrences of following errors:

Tue Apr 21 19:59:21 2015
ORA-19815: WARNING: db_recovery_file_dest_size of 858993459200 bytes is 100.00% used, and has 0 remaining bytes available.
ARC1: Error 19809 Creating archive log file to '+RECO1'
ARCH: Archival stopped, error occurred. Will continue retrying
ORACLE Instance dbname2 - Archival Error
ORA-16038: log 21 sequence# 2506 cannot be archived
ORA-19809: limit exceeded for recovery files

Session id 1262 on instance 2 was doing number of small control file sequential read and none of single IO was stuck in large wait.

@event_hist.sql control.*read session_id=1262 1596 1596
                                 Wait time    Num ASH   Estimated    Estimated    % Event  Estimated
Wait Event                      bucket ms+    Samples Total Waits    Total Sec       Time  Time Graph
------------------------------ ----------- ---------- ----------- ------------ ---------- ------------
control file sequential read           < 1         17     66149.3         66.1       88.3 |######### |
                                      < 16          2       171.8          2.7        3.6 |          |
                                      < 32          3       128.2          4.1        5.5 |#         |
                                     < 128          1        15.6          2.0        2.7 |          |

 

image

Majority of sessions were ultimately waiting for session id 1262 on instance 2 (LGWR process). I think wait counts for control file read went up as LGWR was constantly trying to switch log file but it couldn’t as recovery destination was full. So enq: SQ – contention was the symptom of LGWR spinning on log switch due to no space in recovery destination(db_recovery_file_dest_size).

References:

Advanced Oracle Troubleshooting Guide – Part 11: Complex Wait Chain Signature Analysis

Diagnosing buffer busy waits with the ash_wait_chains.sql script (v0.2)

Update: 04/27/2015

I deliberately filled recovery destination area and then tried to switch log files. Switch log file command was hung and LGWR 10046 trace showed repeated loop of trying to read control file blocks. First two lines shows it was trying to read control file header block from multiplexed control files. Below is the excerpt from LGWR trace file.

nam='control file sequential read' file#=0 block#=1 
nam='control file sequential read' file#=1 block#=1 
nam='control file sequential read' file#=0 block#=40 
nam='control file sequential read' file#=0 block#=42 
nam='control file sequential read' file#=0 block#=43 
nam='control file sequential read' file#=0 block#=815 
nam='control file sequential read' file#=0 block#=46 
nam='control file sequential read' file#=0 block#=1 
nam='control file sequential read' file#=1 block#=1 
nam='control file sequential read' file#=0 block#=40 
nam='control file sequential read' file#=0 block#=42 
nam='control file sequential read' file#=0 block#=43 
nam='control file sequential read' file#=0 block#=815 
nam='control file sequential read' file#=0 block#=46 
nam='control file sequential read' file#=0 block#=1 
nam='control file sequential read' file#=1 block#=1 
nam='control file sequential read' file#=0 block#=40 
nam='control file sequential read' file#=0 block#=42 
nam='control file sequential read' file#=0 block#=43 
nam='control file sequential read' file#=0 block#=815 
nam='control file sequential read' file#=0 block#=46 
nam='control file sequential read' file#=0 block#=1 
nam='control file sequential read' file#=1 block#=1 
nam='control file sequential read' file#=0 block#=40 
nam='control file sequential read' file#=0 block#=42 
nam='control file sequential read' file#=0 block#=43 
nam='control file sequential read' file#=0 block#=815 
nam='control file sequential read' file#=0 block#=46 
nam='control file sequential read' file#=0 block#=1 
nam='control file sequential read' file#=1 block#=1 
nam='control file sequential read' file#=0 block#=40 
nam='control file sequential read' file#=0 block#=42 
nam='control file sequential read' file#=0 block#=43 
nam='control file sequential read' file#=0 block#=815 
nam='control file sequential read' file#=0 block#=46 
nam='control file sequential read' file#=0 block#=1 
nam='control file sequential read' file#=1 block#=1 
nam='control file sequential read' file#=0 block#=40 
nam='control file sequential read' file#=0 block#=42 
nam='control file sequential read' file#=0 block#=43 
nam='control file sequential read' file#=0 block#=815 
nam='control file sequential read' file#=0 block#=46 
nam='control file sequential read' file#=0 block#=1 
nam='control file sequential read' file#=1 block#=1 
nam='control file sequential read' file#=0 block#=40 
nam='control file sequential read' file#=0 block#=42 
nam='control file sequential read' file#=0 block#=43 
nam='control file sequential read' file#=0 block#=815 
nam='control file sequential read' file#=0 block#=46 
nam='control file sequential read' file#=0 block#=1 
nam='control file sequential read' file#=1 block#=1 
nam='control file sequential read' file#=0 block#=40 
nam='control file sequential read' file#=0 block#=42 
nam='control file sequential read' file#=0 block#=43 
nam='control file sequential read' file#=0 block#=815 
nam='control file sequential read' file#=0 block#=46 
nam='control file sequential read' file#=0 block#=1 
nam='control file sequential read' file#=1 block#=1 
nam='control file sequential read' file#=0 block#=40 
nam='control file sequential read' file#=0 block#=42 
nam='control file sequential read' file#=0 block#=43 
nam='control file sequential read' file#=0 block#=815 
nam='control file sequential read' file#=0 block#=46 
nam='control file sequential read' file#=0 block#=1 
nam='control file sequential read' file#=1 block#=1 
nam='control file sequential read' file#=0 block#=40 
nam='control file sequential read' file#=0 block#=42 
nam='control file sequential read' file#=0 block#=43 
nam='control file sequential read' file#=0 block#=815 
nam='control file sequential read' file#=0 block#=46 
nam='control file sequential read' file#=0 block#=1 
nam='control file sequential read' file#=1 block#=1 
nam='control file sequential read' file#=0 block#=40 
nam='control file sequential read' file#=0 block#=42 
nam='control file sequential read' file#=0 block#=43 
nam='control file sequential read' file#=0 block#=815 
nam='control file sequential read' file#=0 block#=46 
nam='control file sequential read' file#=0 block#=1 
nam='control file sequential read' file#=1 block#=1 
nam='control file sequential read' file#=0 block#=40 
nam='control file sequential read' file#=0 block#=42 
nam='control file sequential read' file#=0 block#=43 
nam='control file sequential read' file#=0 block#=815 
nam='control file sequential read' file#=0 block#=46 
nam='control file sequential read' file#=0 block#=1 
nam='control file sequential read' file#=1 block#=1 
nam='control file sequential read' file#=0 block#=40 
nam='control file sequential read' file#=0 block#=42 
nam='control file sequential read' file#=0 block#=43 
nam='control file sequential read' file#=0 block#=815 
nam='control file sequential read' file#=0 block#=46 
nam='control file sequential read' file#=0 block#=1 
nam='control file sequential read' file#=1 block#=1 
nam='control file sequential read' file#=0 block#=40 
nam='control file sequential read' file#=0 block#=42 
nam='control file sequential read' file#=0 block#=43 
nam='control file sequential read' file#=0 block#=815 
nam='control file sequential read' file#=0 block#=46 
nam='control file sequential read' file#=0 block#=1 
nam='control file sequential read' file#=1 block#=1 

March 10, 2015

SQL Plan Tree Visualization

Filed under: Performance Tuning, SQL, Tools, Troubleshooting — vishaldesai @ 8:22 pm

Real Time SQL Monitor Graphical plan from Cloud Control at times is not legible. Using google chart and visualization techniques that I learned from Accenture Enkitec’s and Iggy’s blog, I have create three scripts to quickly display plan in graphical Btree format. The one from real time sql monitoring displays few more metrics such as cardinality, IO and time statistics and I have added some color logic such that if time spend in one plan line id is more than 10% of total elapsed time then display Timeline in red otherwise green.

@getplan_cursor_tree.sql – Display graphical btree plan from cache based on SQL ID and plan_hash_value

@getplan_awr_tree.sql – Display graphical btree plan from AWR metadata based on SQL ID and plan_hash_value

@getplan_realsqlmonitor_tree.sql – Display graphical btree plan from Real Time SQL monitoring based on SQL ID, sql_exec_id etc.

Modify hard coded lines in script:

SPO logs\getplan_realsqlmonitor_tree_&tmenvs..html;

host start chrome C:\Users\U267399\Desktop\Tools\scripts\logs\getplan_realsqlmonitor_tree_&tmenvs..html

Sample output from OEM:

 image

 

Sample html output using getplan_realsqlmonitor_tree.sql: 

image

Full html file https://dl.dropboxusercontent.com/u/48791336/getplan_realsqlmonitor_tree_031615_170343.html

Download

References:

1) http://mauro-pagano.com/2015/03/10/trouble-reading-an-execution-plan-maybe-sqld360-can-help/

2) https://iggyfernandez.wordpress.com/2010/11/26/explaining-the-explain-plan-using-pictures/

May 15, 2014

IO Waits, Average Wait Time and Histogram Heat maps using SQL Developer

Filed under: Tools, Troubleshooting — vishaldesai @ 11:00 pm

Jeff Smith pointed out David Mann’s blog in recent session on SQL Developer Reporting. Using David’s base code I have developed SQL developer heat map reports to visualize, troubleshoot and compare IO related waits.

 image

 

image

From above we can clearly visualize that on 11-MAY-2013 between 2:00 – 3:00 pm average wait time for log file parallel write event was 27.3 ms. The number of waits during same time slot was 10801 which is equivalent to 3 waits per second and that’s not significant. If intermittent slowness was reported by application team and if it was related to commit wait class, DBAs need to engage SA/SAN team to investigate this further.

Below are IO wait histogram reports for log file parallel write event on same database instance. For OLTP workload you want to see bright red boxes for log file parallel write between 1 and 16ms buckets for wait counts and average wait times. Such heat maps can also be used to do relative performance comparison by Day or Day/Hour.

image

 

image

 

Download (I will upload SQL developer report definition files early next week.)

Another example of vertical stacked bar chart.

IO Wait Histogram by Count – db file sequential read

image

 

IO Wait Histogram by Avg Wait Time(s) – db file sequential read

image

January 24, 2014

Build Bind Variables from v$sql_monitor binds_xml column

Filed under: SQL, Troubleshooting — vishaldesai @ 7:41 pm

One of my client had interesting SQL performance issue. Whenever client executes query from ab initio it takes forever and same SQL code from sqlplus runs in less than a minute. Both tools were producing different plan_hash_value. I looked at v$ses_optimizer_env to ensure there were no session level parameters set for ab initio session.

I wanted to run exact SQL from sqlplus, create sql plan baseline so that when SQL is submitted from AI it can use good plan. AI was generating SQL dynamically so I decided get exact SQL text, bind variables and values from v$sql_monitor. I defined bind variables, assigned values and ran SQL from sqlplus and created profile which was eventually used by AI. To automate constructing bind variables and SQL Text from v$sql_monitor, I wrote script called build_bind_sqlmontior.sql.

Script will prompt for Key, SID and SQL_ID. Enter value for at least on prompt and later on enter key value to construct bind variables and SQL Text as shown below:

SQL> @build_bind_sqlmonitor.sql
Please enter the value for Key if known       :
Please enter the value for Sid if known       : 986
Please enter the value for sql_id if known    :

             KEY STATUS              USERNAME   MODULE                      SID SQL_ID        FIRST_REFRESH_TIME   PROGRAM         SQL_TEXT
---------------- ------------------- ---------- -------------------- ---------- ------------- -------------------- --------------- --------------------
   6996503228544 DONE (ALL ROWS)     SYS        sqlplus.exe                 986 8wy5mjmh53vxf 01/24/14 10:41:56    sqlplus.exe     select /*+ monitor f
   8362302828663 DONE (ERROR)        SYS        sqlplus.exe                 986 4bkxr36kasm7s 01/24/14 10:40:51    sqlplus.exe     select /*+ monitor f
  16471201083509 DONE (ERROR)        SYS        sqlplus.exe                 986 azb329svj1ajd 01/24/14 10:39:36    sqlplus.exe     select /*+ monitor f
   7082402574450 DONE (ERROR)        SYS        sqlplus.exe                 986 3036w6mx13rq5 01/24/14 10:38:36    sqlplus.exe     select /*+ monitor f
   5845451993201 DONE (ERROR)        SYS        sqlplus.exe                 986 20fmy44010wvw 01/24/14 10:38:00    sqlplus.exe     select /*+ monitor f
  11643657842205 DONE (ALL ROWS)                                            986 bfjf698jtp6n1 01/24/14 03:10:14
   7421704990227 DONE                                                       986 2vn8ztuzaq3k4 01/24/14 03:10:11
  14856293379585 DONE (ALL ROWS)                                            986 53afdbcv9637w 01/24/14 03:10:10
.....
.....
Please enter Key from above       : 6996503228544

variable SYS_B_0 VARCHAR2(32);
variable SYS_B_1 VARCHAR2(32);
variable SYS_B_2 NUMBER;

exec :SYS_B_0 := '31-OCT-12 00.00.00';
exec :SYS_B_1 := 'DD-MON-YY HH24:MI:SS';
exec :SYS_B_2 := 30205578;

select /*+ monitor full(ism) */ *
from ism.table_name ism
where col1=to_date(:"SYS_B_0",:"SYS_B_1")
and   col2=:"SYS_B_2";

SQL> variable SYS_B_0 VARCHAR2(32);
SQL> variable SYS_B_1 VARCHAR2(32);
SQL> variable SYS_B_2 NUMBER;
SQL>
SQL> exec :SYS_B_0 := '31-OCT-12 00.00.00';

PL/SQL procedure successfully completed.

SQL> exec :SYS_B_1 := 'DD-MON-YY HH24:MI:SS';

PL/SQL procedure successfully completed.

SQL> exec :SYS_B_2 := 30205578;

PL/SQL procedure successfully completed.

SQL> select /*+ monitor full(ism) */ *
  2  from ism.table_name ism
  3  where col1=to_date(:"SYS_B_0",:"SYS_B_1")
  4  and   col2=:"SYS_B_2";

.....

1 row selected.

Download Script

If there is any data type conversion script may not produce reliable output.

January 22, 2014

Yet Another Case of multiple child cursors, BIND_MISMATCH and OPTIMIZER_MISMATCH

Filed under: Performance Tuning, Troubleshooting — vishaldesai @ 9:08 pm

One of my client had unpredictable response time for bunch of SQL statements. I did not have any sqlid or sql code to start with so I started by running Kerry’s unstable_plans.sql. As per awr_plan_stats.sql, 3799146274 was good hash and 2775678588 was bad hash.

Output from unstable_plans.sql

SQL_ID        SUM(EXECS)   MIN_ETIME   MAX_ETIME   NORM_STDDEV
------------- ---------- ----------- ----------- -------------
....
djtwm74rrch17       1709         .00       23.69    7,395.6254
..

@awr_plan_stats
Enter value for sql_id: djtwm74rrch17

SQL_ID        PLAN_HASH_VALUE        EXECS    AVG_ETIME AVG_PX_SERVERS AVG_CPU_TIME            AVG_LIO          AVG_PIO
------------- --------------- ------------ ------------ -------------- ------------ ------------------ ----------------
djtwm74rrch17      3799146274          462        1.042     .004329004         .000                7.0               .1
djtwm74rrch17      2775678588        1,250   29,602.465          .0016        2.161          157,655.3        157,725.4

SQL_TEXT for djtwm74rrch17

SELECT ...
FROM TAB1 PAL,
  TAB2 COMPANY
WHERE PAL.CPY_ID      = COMPANY.CPYID
AND ( PAL.LOAN_NUMBER = :"SYS_B_0" )
ORDER BY ...

We clearly had multiple child cursors for given hash and had two different hash values. Child 0 is the first child, Child 1 was created due to bind_mismatch, child 2 was created due to optimizer_mismatch marking child 0 as non shareable and child 3 was created due to optimizer and bind mismatch marking child 1 as non shareable..

SQL> select sql_id,plan_hash_value,child_number,is_shareable from gv$sql where sql_id='djtwm74rrch17' and inst_id=2;

SQL_ID        PLAN_HASH_VALUE CHILD_NUMBER I
------------- --------------- ------------ -
djtwm74rrch17      3799146274            0 N
djtwm74rrch17      2775678588            1 N
djtwm74rrch17      3799146274            2 Y
djtwm74rrch17      2775678588            3 Y

select * from GV$SQL_SHARED_CURSOR where sql_id='djtwm74rrch17'
and inst_id=2;

INST_ID    SQL_ID            ADDRESS                CHILD_ADDRESS    CHILD_NUMBER    OPTIMIZER_MISMATCH    BIND_MISMATCH
2        djtwm74rrch17    000000025C7B1F90    000000025C8296D0        0                        N                   N
2        djtwm74rrch17    000000025C7B1F90    000000025C6E2DF0        1                        N                   Y
2        djtwm74rrch17    000000025C7B1F90    000000025C6E4210        2                        Y                   N
2        djtwm74rrch17    000000025C7B1F90    000000025C7B90E0        3                        Y                   Y

Child cursors 2 and 3 were created due to optimizer_mismatch and parameter that caused optimizer_mismatch was _pga_max_size. But we never set or change _pga_max_size on our databases. But databases were configured with AMM. _pga_max_size is derived from pga_aggregate_target so whenever PGA was resized it was affecting _pga_max_size making existing cursors non shareable.

Based on output from gv$sql_optimizer_env
                    Child        Child        Child        Child
Parameter                0            1            2            3
_pga_max_size    229360 KB    229360 KB    239200 KB    239200 KB
SQL> show parameter memory%target

NAME                                 TYPE                             VALUE
------------------------------------ -------------------------------- ------------------------------
memory_max_target                    big integer                      8G
memory_target                        big integer                      8G

And the reason for bind mismatch was using different data types for literal values as shown below:

SQL> select sql_id,child_number,name,position,datatype,datatype_string,max_length,last_captured,value_string from GV$SQL_BIND_CAPTURE where inst_id=2 and sql_id='djtwm74rrch17'; 

SQL_ID        CHILD_NUMBER NAME                             POSITION   DATATYPE DATATYPE_STRING MAX_LENGTH LAST_CAPTURED     VALUE_STRI
------------- ------------ ------------------------------ ---------- ---------- --------------- ---------- ----------------- ----------
djtwm74rrch17            3 :SYS_B_0                                1          2 NUMBER                  22 01/22/14 08:14:14 477026652
djtwm74rrch17            2 :SYS_B_0                                1          1 VARCHAR2(32)            32 01/22/14 10:14:44 0476735873
djtwm74rrch17            1 :SYS_B_0                                1          2 NUMBER                  22 01/21/14 10:49:20 476783261
djtwm74rrch17            0 :SYS_B_0                                1          1 VARCHAR2(32)            32 01/21/14 15:45:13 0476636964 

Predicate section of plan shows to_number function used for hash 2775678588. Same information can be derived from v$sql_plan_statistics_all.

SQL_ID  djtwm74rrch17, child number 2
-------------------------------------
Plan hash value: 3799146274

-----------------------------------------------------------------------------------------------------
| Id  | Operation                      | Name               | Rows  | Bytes | Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT               |                    |       |       |     6 (100)|          |
|   1 |  SORT ORDER BY                 |                    |     1 |   313 |     6  (17)| 00:00:01 |
|   2 |   NESTED LOOPS                 |                    |       |       |            |          |
|   3 |    NESTED LOOPS                |                    |     1 |   313 |     5   (0)| 00:00:01 |
|   4 |     TABLE ACCESS BY INDEX ROWID| TAB1               |     1 |   279 |     4   (0)| 00:00:01 |
|*  5 |      INDEX RANGE SCAN          | PKTAB1             |     1 |       |     3   (0)| 00:00:01 |
|*  6 |     INDEX UNIQUE SCAN          | TAB1_CPYID         |     1 |       |     0   (0)|          |
|   7 |    TABLE ACCESS BY INDEX ROWID | TAB2               |     1 |    34 |     1   (0)| 00:00:01 |
-----------------------------------------------------------------------------------------------------

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

   5 - access("PAL"."LOAN_NUMBER"=:SYS_B_0)
   6 - access("PAL"."CPY_ID"="COMPANY"."CPYID")
   
   
SQL_ID  djtwm74rrch17, child number 3
-------------------------------------
Plan hash value: 2775678588

----------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name               | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |                    |       |       | 44394 (100)|          |
|   1 |  SORT ORDER BY                |                    |     1 |   313 | 44394   (1)| 00:08:53 |
|   2 |   NESTED LOOPS                |                    |       |       |            |          |
|   3 |    NESTED LOOPS               |                    |     1 |   313 | 44393   (1)| 00:08:53 |
|*  4 |     TABLE ACCESS FULL         | TAB1               |     1 |   279 | 44392   (1)| 00:08:53 |
|*  5 |     INDEX UNIQUE SCAN         | TAB1_CPYID            |     1 |       |     0   (0)|          |
|   6 |    TABLE ACCESS BY INDEX ROWID| TAB2               |     1 |    34 |     1   (0)| 00:00:01 |
----------------------------------------------------------------------------------------------------


   4 - filter(TO_NUMBER("PAL"."LOAN_NUMBER")=:SYS_B_0)
   5 - access("PAL"."CPY_ID"="COMPANY"."CPYID")
   
   
SQL> l
  1   select distinct sql_id,PLAN_HASH_VALUE,id,PARENT_ID,ACCESS_PREDICATES,FILTER_PREDICATES FROM gv$sql_plan_statistics_all
  2   WHERE sql_id = 'djtwm74rrch17' and inst_id=2
  3   and (ACCESS_PREDICATES is not null or FILTER_PREDICATES is not null)
  4*  order by PLAN_HASH_VALUE
SQL> /

SQL_ID        PLAN_HASH_VALUE         ID  PARENT_ID ACCESS_PREDICATES                        FILTER_PREDICATES
------------- --------------- ---------- ---------- ---------------------------------------- ----------------------------------------
djtwm74rrch17      2775678588          5          3 "PAL"."CPY_ID"="COMPANY"."CPYID"
djtwm74rrch17      2775678588          4          3                                          TO_NUMBER("PAL"."LOAN_NUMBER")=:SYS_B_0
djtwm74rrch17      3799146274          6          3 "PAL"."CPY_ID"="COMPANY"."CPYID"
djtwm74rrch17      3799146274          5          4 "PAL"."LOAN_NUMBER"=:SYS_B_0

Unfortunately AWR does not store access_predicates and filter_predicates so if cursors have edged out it won’t be possible to troubleshoot such random behavior.

November 26, 2013

Compare IO outliers

Filed under: Performance Tuning, Tools, Troubleshooting — vishaldesai @ 9:47 pm

Oracle SQL Developer has nice reporting capability to plot charts. To compare IO outliers using db_hist_event_histogram between two periods, I have created couple of reports for quick comparison.

When you click on report, it will prompt you to select database and input event, period one start snap and end snap, period two start and end snap.

Compare IO wait count outliers by %

image

Compare IO wait count outliers by Value

image

Compare IO wait time outlier by %

image

IO latency for all snaps by Day

image

IO latency for last 24 hours

image

Download link for report definition file.

PS Current version of SQL developer supports only 5 different colors for pie charts so there is overlap of colors in first 3 charts.

October 7, 2013

SQL Developer Child Reports and Drill Down

Filed under: Tools, Troubleshooting — vishaldesai @ 10:36 pm

SQL Developer has some cool reporting capability. Using these features and some of my favorite scripts, I can now quickly troubleshoot Oracle Database related issue.

Example: For given database session, I can run Tanel’s asqlmon, look at historical SQL performance using Kerry’s AWR scripts, and drill down into IO latency with just point and click.

 

July 5, 2013

v$event_histogram – buckets of time in Nth/Snap interval

Filed under: Performance Tuning, Tools, Troubleshooting — vishaldesai @ 6:22 pm

v$event_histogram stores cumulative data since instance startup. To monitor real time events and under what latency bucket they fall under, I have written script called wait_histogram_wc_pct.sql. Script will display percentage of wait counts that falls into individual latency bucket.

Example: As shown below in last line, 25% of direct path read events waited for >32ms and <64ms (307 out of 1228  events).

SQL> @wait_histogram_wc_pct.sql 'direct path read' 10 10
---------------------------------------------------------------Percent Wait Count--------------------------------------------------------------------------|
Event               |Time                |<1    |<2    |<4    |<8    |<16   |<32   |<64   |<128  |<256  |<512  |<1024 |<2048 |<4096 |<8192 |Tot Wait Count |
-----------------------------------------------------------------------------------------------------------------------------------------------------------|
direct path read    |07/05/13 11:49:51   |     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|              1|
direct path read    |07/05/13 11:50:01   |     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|              1|
direct path read    |07/05/13 11:50:11   |     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|              1|
direct path read    |07/05/13 11:50:21   |     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|              1|
direct path read    |07/05/13 11:50:31   |     1|     2|     3|     7|    17|    38|    21|     7|     3|     0|     0|     0|     0|     0|           1212|
direct path read    |07/05/13 11:50:41   |     2|     2|     6|    11|    20|    33|    20|     5|     1|     0|     0|     0|     0|     0|           2696|
direct path read    |07/05/13 11:50:51   |     4|     3|     6|    11|    20|    29|    19|     7|     1|     0|     0|     0|     0|     0|           2492|
direct path read    |07/05/13 11:51:01   |     4|     3|     6|    11|    18|    24|    25|     9|     1|     0|     0|     0|     0|     0|           2164|
direct path read    |07/05/13 11:51:12   |     2|     2|     4|     9|    16|    23|    25|    16|     3|     0|     0|     0|     0|     0|           1588|
direct path read    |07/05/13 11:51:22   |     1|     2|     3|     7|    13|    19|    27|    21|     6|     0|     0|     0|     0|     0|           1228|

Total wait counts may not be 100% accurate if v$event_histogram gets updated between last and first sample.

To monitor historical events from AWR in similar fashion you can use awr_wait_hist_wc_pct.sql

SQL> @awr_wait_hist_wc_pct.sql
Please enter start_date(mm/dd/yy)    :07/05/13
Please enter end_date  (mm/dd/yy)    :07/05/13


     14757 05-JUL-13 09.00.57.689 AM
     14758 05-JUL-13 09.10.58.136 AM
     14759 05-JUL-13 09.20.58.580 AM
     14760 05-JUL-13 09.30.59.208 AM
     14761 05-JUL-13 09.40.59.867 AM
     14762 05-JUL-13 09.50.00.963 AM
     14763 05-JUL-13 10.00.02.200 AM
     14764 05-JUL-13 10.10.03.637 AM
     14765 05-JUL-13 10.20.04.821 AM
     14766 05-JUL-13 10.30.05.240 AM
     14767 05-JUL-13 10.40.05.723 AM
     14768 05-JUL-13 10.50.06.094 AM
     14769 05-JUL-13 11.00.06.516 AM
     14770 05-JUL-13 11.10.07.016 AM
     14771 05-JUL-13 11.20.07.402 AM
     14772 05-JUL-13 11.30.07.838 AM
     14773 05-JUL-13 11.40.08.306 AM
Enter value for start snap_id   :14757
Enter value for end snap_id     :14773
Enter wait event                :direct path read
Enter instance number for RAC   :1
---------------------------------------------------------------Percent Wait Count--------------------------------------------------------------------------|
Event               |Time                |<1    |<2    |<4    |<8    |<16   |<32   |<64   |<128  |<256  |<512  |<1024 |<2048 |<4096 |<8192 |Tot Wait Count |
-----------------------------------------------------------------------------------------------------------------------------------------------------------|
direct path read    |07/05/13 09:00      |     0|     0|    33|    33|    33|     0|     0|     0|     0|     0|     0|     0|     0|     0|              3|
direct path read    |07/05/13 09:10      |    50|     0|    50|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|              2|
direct path read    |07/05/13 09:20      |     2|     3|     6|    11|    20|    36|    15|     5|     1|     0|     0|     0|     0|     0|           6002|
direct path read    |07/05/13 09:30      |     3|     3|     6|    10|    19|    33|    18|     6|     1|     0|     0|     0|     0|     0|         158867|
direct path read    |07/05/13 09:40      |     3|     3|     6|    11|    20|    30|    20|     7|     1|     0|     0|     0|     0|     0|          82122|
direct path read    |07/05/13 09:50      |     2|     3|     5|     9|    15|    22|    25|    15|     5|     0|     0|     0|     0|     0|          27698|
direct path read    |07/05/13 10:00      |     2|     2|     5|     9|    15|    24|    24|    15|     4|     0|     0|     0|     0|     0|          59854|
direct path read    |07/05/13 10:10      |     3|     3|     5|    10|    16|    24|    25|    14|     2|     0|     0|     0|     0|     0|          51421|
direct path read    |07/05/13 10:20      |     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|              0|
direct path read    |07/05/13 10:30      |    20|    20|     0|    40|    20|     0|     0|     0|     0|     0|     0|     0|     0|     0|              5|
direct path read    |07/05/13 10:40      |     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|              0|
direct path read    |07/05/13 10:50      |    60|     0|     0|     0|     0|    40|     0|     0|     0|     0|     0|     0|     0|     0|              5|
direct path read    |07/05/13 11:00      |    33|    33|     0|    33|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|              3|
direct path read    |07/05/13 11:10      |     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|              0|
direct path read    |07/05/13 11:20      |    50|     0|     0|    50|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|              2|
direct path read    |07/05/13 11:30      |    50|     0|     0|    50|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|              2|
direct path read    |07/05/13 11:40      |   100|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|     0|              1|

If you make any enhancements, find any bug with scripts or have any other better way to monitor this, please let me know.

Download Scripts

July 3, 2013

v$event_histogram

Filed under: Performance Tuning, Troubleshooting — vishaldesai @ 8:48 pm

Luca has written awesome script to visualize Oracle latency using Heat Maps. Many times Management appreciate numbers and percentages so my script will attempt to show those numbers since instance startup.

SQL> @wait_histogram direct%path%read

                                                                                % Wait Roll % Wait   % Wait Roll % Wait
EVENT                               WAIT_TIME_MILLI_RANGE          WAIT_COUNT    Count       Count     Time        Time LAST_UPDATE_TIME
----------------------------------- ------------------------------ ---------- -------- ----------- -------- ----------- ---------------------------------------------------
direct path read                    4096-8192                               1        0           0     0              0 02-JUL-13 03.15.05.925862 PM -05:00
direct path read                    2048-4096                              25        0           0     0              0 03-JUL-13 09.05.04.647574 AM -05:00
direct path read                    1024-2048                              54        0           0     0              0 03-JUL-13 12.40.05.158016 PM -05:00
direct path read                    512-1024                              798        0           0     1              1 03-JUL-13 01.27.50.565441 PM -05:00
direct path read                    256-512                              6775        0           0     5              6 03-JUL-13 02.35.25.224134 PM -05:00
direct path read                    128-256                             53429        3           3    18             24 03-JUL-13 02.35.30.723528 PM -05:00
direct path read                    64-128                             158033        9          12    26             50 03-JUL-13 02.35.31.271218 PM -05:00
direct path read                    32-64                              295652       17          29    25             75 03-JUL-13 02.35.31.168757 PM -05:00
direct path read                    16-32                              371819       21          50    15             90 03-JUL-13 03.17.51.706468 PM -05:00
direct path read                    8-16                               310634       18          68     6             96 03-JUL-13 03.17.36.320652 PM -05:00
direct path read                    4-8                                228440       13          81     2             98 03-JUL-13 03.17.36.327927 PM -05:00
direct path read                    2-4                                153154        9          90     1             99 03-JUL-13 03.17.06.015746 PM -05:00
direct path read                    1-2                                 89236        5          95     0             99 03-JUL-13 03.17.51.710201 PM -05:00
direct path read                    0-1                                 93204        5         100     0             99 03-JUL-13 03.35.50.715609 PM -05:00

Avg wait time ms
----------------
      32.7397445

Download

What’s wrong with the Database?

Filed under: Troubleshooting — vishaldesai @ 8:29 pm

My Development team started complaining that application startup hangs when it tries to connect to database. To verify general connectivity, I asked them to verify hostname, port and service name. I converted JDBC URL to TNS entry and verified database connectivity from SQLPLUS. While I was working on this development issue for about 15 minutes, I was asked following questions via different modes of communication:

What’s wrong with the database? What changed on database since last week? Were there any patches applied to database server? What are top wait events on database? How is the performance of oracle database? Is listener up and running? Can DBA’s restart database?

We have thousands of database running at my client site and I was overwhelmed by number and kind of questions that I was asked for this issue. My development team was not very happy as I ignored all questions except for listener question because I was able to connect using SQLPLUS from my client PC.

Verified following items:

– Can connect to database from my client laptop to database server using database host, port and service name via SQLPLUS.

– telnet dbhostname port from application server was working fine

– From database audit log, active session history and listener logs, I did not notice any session requested/established from application server.

– Application server startup just hangs. It does not throw any ORA- errors.

That tells me that issue is outside database server. I was told that SQLPLUS test is not valid as application is using JDBC thin driver. I think that was a valid concern but I ran SQLPLUS test to prove I can connect to database from other client.

I started searching Google to find sample java programs to test database connectivity using JDBC. While I was searching for sample program, development team reported that System Administrator found some issue with application server OS and they have to reboot application server.

I found following link which could be very handy to test database connectivity using oracle JDBC driver.

http://www.mkyong.com/jdbc/connect-to-oracle-db-via-jdbc-driver-java/comment-page-1/#comment-135707

Sample program: OracleJDBC.java

import java.sql.DriverManager;
import java.sql.Connection;
import java.sql.SQLException;
 
public class OracleJDBC {
    public static void main(String[] argv) {
        System.out.println("-------- Oracle JDBC Connection Testing ------");
        try {
            Class.forName("oracle.jdbc.driver.OracleDriver");
        } catch (ClassNotFoundException e) {
            System.out.println("Where is your Oracle JDBC Driver?");
            e.printStackTrace();
            return;
        }
        System.out.println("Oracle JDBC Driver Registered!");
        Connection connection = null;
        try {
            connection = DriverManager.getConnection("jdbc:oracle:thin:@xxx:port:servicename", "dbsnmp","monitor");
            connection = DriverManager.getConnection("jdbc:oracle:thin:@//xxx:port/SID", "dbsnmp","monitor");
        } catch (SQLException e) {
            System.out.println("Connection Failed! Check output console");
            e.printStackTrace();
            return;
        }
        if (connection != null) {
            System.out.println("You made it, take control your database now!");
        } else {
            System.out.println("Failed to make connection!");
        }
    }
}

Make sure JDK is installed on your client PC. Set CLASSPATH and PATH variables.

c:\oracle\product>javac OracleJDBC.java

c:\oracle\product>java -cp .;C:\oracle\product\11.2.0\client_1\jdbc\lib\ojdbc6.jar OracleJDBC
-------- Oracle JDBC Connection Testing ------
Oracle JDBC Driver Registered!
Database connectivity is fine, take control of your Application now!

In firefighting situation, DBA’s can quickly run sample program to test database connectivity from client PC or application server to prove nothing is wrong with the Database. :)

Older Posts »

The Silver is the New Black Theme. Blog at WordPress.com.

Follow

Get every new post delivered to your Inbox.

Join 36 other followers