“external table write” wait events… but I am only running a query?

I was helping a customer debug some external table load problems.  They are developing some code to do massive inserts via external tables.  As the code was being tested, we saw a fair number of tests that were doing simple queries of an external table.  I expected to see “external table read” wait events, but was surprised when we saw more “external table write” wait events than reads.

I thought this was due to writes to the “log” file and possible “bad” file, but I had to be sure.  I searched the docs but could not find reference to this wait event.  I specifically was seeing the following:

WAIT #139931007587096: nam='external table write' ela= 7 filectx=139931005791096 file#=13 size=41 obj#=-1 tim=1398264093597968
WAIT #139931007587096: nam='external table write' ela= 3 filectx=139931005791096 file#=13 size=89 obj#=-1 tim=1398264093597987

I searched on how to debug the filectx and file# but still couldn’t find anything.  So, I resorted to my good old friend “strace” from the Linux side of the house.  By running “strace” on the oracle shadow process, I was able to find indeed that these write events were to going to the LOG file for the external table.

mylap:EXTW glennf$ egrep 'write\(13' strace-truss-trace.txt
 write(13, "\n\n LOG file opened at 04/23/14 0"..., 41) = 41
 write(13, "KUP-05004: Warning: Intra sour"..., 100) = 100
 write(13, "Field Definitions for table ET_T"..., 36) = 36
 write(13, " Record format DELIMITED, delim"..., 43) = 43
 write(13, " Data in file has same endianne"..., 51) = 51
 write(13, " Rows with all null fields are "..., 41) = 41
 write(13, "\n", 1) = 1
 write(13, " Fields in Data Source: \n", 26) = 26
 write(13, "\n", 1) = 1
 write(13, " ID "..., 47) = 47
 write(13, " Terminated by \"7C\"\n", 25) = 25
 write(13, " Trim whitespace same as SQ"..., 41) = 41
 write(13, " TDATE "..., 46) = 46
  ....
  ....

Each time you open an external table, the time is logged as well the table definition.  We have some very wide tables so there was actually more data logged than queried.  With the proper amount of data now in the dat files, we are indeed seeing more “external table read” requests as expected.   Regardless, this was a fun exercise.

So, the moral of the story… Sometimes you have turn over a few rocks and drill down a bit to find the pot of gold.

 

Analyzing IO at the Cell level with cellcli… a new and improved script

Recently I had the pleasure of corresponding with Hans-Peter Sloot.  After looking at my simple tool in this post to gather cell IO data from cellcli, he took it a several steps further and created a nice python version that goes to the next level to pull IO statistics from the cells.

current_rw_rq.py

This script provides breaks down the IO by “Small” and “Large” as is commonly done by the Enterprise manager.  It also provides a summary by cell.  Here is a sample output from this script.

Hans-Peter also added two other scripts to drill in to historical data stored in cellcli.    Thanks for sharing your tools and further expanding my toolbox!

Analyzing IO at the Exadata Cell level… iostat summary

While analyzing Write-Back cache activity on Exadata storage cells, I wanted something to interactively monitor IO while I was running various tests.  The problem is summarizing the results from ALL storage cell.  So, I decided to use my old friend “iostat” and a quick easy script to roll up the results for both DISK and FLASH.  This allowed me to monitor the IOPS, IO size, wait times, and service times.  

The “iostat-all.sh” tool shows the following data:

day           time  device  r      w   rs       ws     ss    aw    st
---------------------------------------------------------------------
 2013-06-24 14:40:11 DISK  47  40252   54  2667941  66.15  0.28  0.07
 2013-06-24 14:40:11 FLASH  9  40354  322  2853674  70.70  0.13  0.13
 2013-06-24 14:41:13 DISK  48  39548   80  2691362  67.95  0.31  0.08
 2013-06-24 14:41:13 FLASH  9  53677  324  3975687  74.06  0.14  0.13
…

Hopefully this will be useful for those that like to dive into the weeds using our good old friends.

Dtrace probes in Oracle 12c… v$kernel_io_outlier is populated by dtrace!!

Oracle 12c certainly has some great features, but for the performance guy like myself, performance monitoring features are particularly interesting.  There are three new v$ tables that track anomalies in the IO path.  The idea is to provide more information about really poorly performing IO that lasts more than 500ms.

  • V$IO_OUTLIER : tracks the attributies of an IO.  The size, latency as well as ASM information is recorded.
  • V$LGWRIO_OUTLIER : tracks information specifically on Log writer IO.

These two tables are going to be useful to monitor when performance issues occur.  I can already see the SQL scripts to monitor this activity starting to pile up.  But, there is one little extra table that dives even further into the IO stack using Dtrace.

  • “V$KERNEL_IO_OUTLIER” : This table dives into the KERNEL to provide information about Kernel IO.  This table uses my old friend Dtrace to provide information about where the waits are occurring when Kernel IO is in-play.  This shows the time for every step involved in the setup and teardown Kernel IO.   This information allows us to more easily debug anomalies in the IO stack.

Back in 2009 when Oracle was buying Sun I posted “Oracle buys Sun! Dtrace probes for Oracle?” and lamented on how cool that would be… It is good to know that someone was listening :)

Analyzing IO at the Exadata Cell level… a simple tool for IOPS.

Lately I have been drawn into to a fare number of discussions about IO characteristics while helping customers run benchmarks.  I have been working with a mix of developers, DBAs, sysadmin, and storage admins.  As I have learned, every group has there own perspective – certainly when it comes to IO and performance.

  • Most DBA’s want to see data from the DB point of view so AWR’s or EM works just fine.
  • Most System Admin’s look at storage from the Filesystem or ASM disk level.
  • Storage Admins want to see what is going on within the array.
  • Performance geeks like myself, like to see all up and down the stack :)

As part of pulling back the covers, I came up with a simple little tool for show IOPS at the cell level.

Mining IO statistics from cellcli

The cellsrv process collects data about various events and performance metrics in an Exadata storage cell.  I certainly am a huge fan of the table and index usage data gathered using the  “pythian_cell_cache_extract.pl” written by Christo Kutrovsky.  It is really provides a great look inside the Exadata Smart Flash Cache.  So, this got me to thinking.  What about IOPS data?

With the introduction of the Write Back Flash cache in X3, there is much more analysis about what is going to flash vs disk – and how what is written to flash is flushed to disk.

To look at all the current metrics gathered from the storage cells in your Exadata or SuperCluster you can run “cellcli -e list metriccurrent” on all the storage cells.  The “metriccurrent” parameters are updated every minute by cellsrv to store performance data.  There are a few convient parameters that can be used to sum up all the IOPS.

  • CD_IO_RQ_R_LG_SEC + CD_IO_RQ_R_SM_SEC
  • CD_IO_RQ_W_LG_SEC + CD_IO_RQ_W_SM_SEC

These parameters shore the number of IO/sec for reads and writes.  By mining this data and breaking it down by “FD” vs “CD” you can see hit ratios for reads from an overall cell point of view, but now you can also see how many writes are going to FLASH vs DISK.

The “ciops-all.sh” script will look at all the cells and sum up all the IOPS and report the findings.  This is very useful to get a quick look at the IO profile in the cells.

[oracle@exa6db01 WB]$ ./ciops-all.sh
FLASH_READ_IOPS: 6305
DISK_READ_IOPS: 213
FLASH_WRITE_IOPS: 488203
DISK_WRITE_IOPS: 6814
TOTAL_NUMBER_OF_DRIVES: 84
WRITE_PCT_to_FLASH: 98
READ_PCT_from_FLASH: 96
IOPS_PER_DISK: 83

This can be very helpful when trying to figure out if you need to go with high performance or high capacity disks.  This case shows most IO going to the flash and only 83 IOPS are spilled to each disk.  So, with this case HC disks would be a fine choice.  With a simple modification, I made the “ciops-mon.sh” script to print out the throughput every few minutes to graph the results over time.

ciops_data_x3-2

This has been helpful as I have been investigating and explaining the inter-workings of the Exadata smart flash cache.  Hopefully, you will find this useful when trying to analyze and understand Exadata Cell level IO with your workload.

Solaris Eye for the Linux Guy… Part III (hugepages = ISM)

This post has been a long time coming but recently, I have started working on some SPARC SuperCluster POC’s with customers and I am getting re-acquainted with my old friend Solaris and SPARC.

If you are a Linux performance guy you have likely heard of HugePages.   Huge pages are used to increase the performance of large memory machines but requiring fewer TLB‘s .  I am not going to go into the details TLB’s, but every modern chip supports multiple memory page sizes.

So how do you get huge pages with Solaris?

Do nothing – it is the DEFAULT with Oracle running on Solaris.

The “use_ism” parameter used to be used to control this, but it has been moved to the “_underbar” category these days since there is really no reason whatsoever to change it.   I remember doing tests back in the Solaris 8 days with/without ISM pages to show the performance differences and truly it was and still is a good thing.

How are ISM/Huge pages used with Oracle running on Solaris?

At first, ISM pages are only used for the SGA so OLTP style environments benefited the most from ISM.   With Oracle 10 on Solaris, it was also allowed for the PGA.  So, if you were doing have PGA activity like a HASH join or sort, you would benefit from larger page sizes as well.

With Solaris, it is easy to see if the page sizes of any running process by simply running the “pmap(2)” command. 

root@ssc401:~# pmap -xs 23189
 23189: ora_pmon_HC1
 Address Kbytes RSS Anon Locked Pgsz Mode Mapped File
 0000000100000000 64 64 - - 8K r-x-- oracle
 0000000100010000 48 48 - - - r-x-- oracle
 000000010001C000 64 64 - - 8K r-x-- oracle
 ...
 000000010D420000 256 256 64 - 64K rwx-- oracle
 000000010D460000 64 64 - - - rwx-- oracle
 ...
 ... 
 000000010D540000 2304 2304 2304 - 64K rwx-- [ heap ]
 0000000380000000 262144 262144 - 262144 256M rwxsR [ ism shmid=0xf00007e ]
 0000000390000000 65536 65536 - 65536 4M rwxsR [ ism shmid=0xf00007e ]
 0000000400000000 31457280 31457280 - 31457280 2G rwxsR [ ism shmid=0x600007f ]
 0000000B80000000 1572864 1572864 - 1572864 256M rwxsR [ ism shmid=0x600007f ]
 0000000BE0000000 196608 196608 - 196608 4M rwxsR [ ism shmid=0x600007f ]
 0000000C00000000 24 24 - 24 8K rwxsR [ ism shmid=0x7000000 ]
 FFFFFFFF5A800000 16 16 - - 8K r-x-- libodm11.so
 FFFFFFFF5A902000 8 8 8 - 8K rwx-- libodm11.so
 FFFFFFFF60500000 64 64 - - 64K r-x-- libclsra11.so
 FFFFFFFF60510000 24 24 - - - r-x-- libclsra11.so
 ...
 FFFFFFFF7D1FC000 8 8 - - 8K r-x-- libsched.so.1
 FFFFFFFF7D1FE000 8 8 - - 8K r-x-- libdl.so.1
 FFFFFFFF7D300000 8 8 8 - 8K rw--- [ anon ]
 FFFFFFFF7D400000 8 8 8 - 8K rw--- [ anon ]
 FFFFFFFF7D500000 8 8 8 - 8K rw--- [ anon ]
 FFFFFFFF7FFE0000 128 128 128 - 64K rw--- [ stack ]

Notice that the “text”, “heap”, “anon”, “stack”, and shared memory can all use different page sizes.  In this case, the SGA is backed by 2G, 256M, 4M, 8k ISM pages.

So what about Dynamic ISM?  Should I use ISM or DISM?

So, Dynamic ISM was introduced to resize the SGA.  DISM is really just ISM memory that can be paged.  This can be useful when you have HUGE memory machines and want to resize the SGA without taking down the instance.  But why is this needed?

  • Single-Instance availability on HUGE machines that can dynamically add/replace MEMORY.  Machines like the E10k/E25k/M9000/M10… etc all allow you to add components on the fly without restarted Solaris.  Let’s say have have a failing memory board.  You could “Shrink” the SGA so that it fits into the surviving space and while you service the faulty board.  Also, say you start with a 1/2 populated machine.  You can add memory without and grow the SGA without stopping the instance.
  • Consolidation or Cloud like services.  In this environment you can resize running instances on the fly in order to free up memory for new instances.

Personally, I don’t see a lot of use for DISM with the SuperCluster.   If you have RAC you don’t need DISM for availability reasons and with cloud/consolidation I think multiple instances within a single server is not the best practice going forward.   At one point you needed to use DISM for NUMA features, but that is not case with 11.2.0.3.

MAA tests on Exadata… demystifying availability tests

MAA tests on Exadata… demystifying availability tests

I have not had a lot of time to post recently due to various reasons and a switch in jobs at Oracle.  I currently am 100% dedicated to working in the Oracle Solution Center to help customers test the performance on Oracle’s engineered solutions.  So, why am I sending this link?

Regardless of the performance tests that are performed, I often spend a fair amount of time showing the Availability aspects as well.  Hopefully this video will help to demystify the availability aspects of Exadata.



Follow

Get every new post delivered to your Inbox.

Join 340 other followers