Oracle

February 23, 2011

Caution while dropping unused columns with checkpoint

Filed under: Uncategorized — srivenu @ 9:19 am

Some of the optional clauses in SQL statements sound so naive and misleading while actually hiding the immense risk involved in using them. I think oracle should use appropriate terminology for such clauses.

One such clause is the “CHECKPOINT” in the DDL “ALTER TABLE …. DROP UNUSED COLUMNS CHECKPOINT”.
May be it would have been more appropriate if it was “ALTER TABLE …. DROP UNUSED COLUMNS CHECKPOINT YOU ARE STUCK HERE TILL COMPLETION DUMBO” !

Case in point –
In one of the databases, we have a 6TB partitioned table into 100GB is loaded every day. A couple of months ago, one of the columns in the table was set to UNUSED as the developers wanted it to be dropped. During one of the weekend downtimes, one of the DBA’s wanted to drop the unused column. Being unsure of the time it would take and to avoid any UNDO issue, he decided to use the CHECKPOINT clause (to be fair, I might have too).

He cancelled the session immediately, but trouble manifested soon after. Any sort of access to the table starting throwing the error “table in not usable state”. We could not parallelize the column drop session. We could not afford to proceed in one serial session as it would have taken 18 days to complete!

Quick search on the net revealed this note. We could not implement the workaround suggested in the node immediately as it involved dictionary modification and had to suffer several hours of critical functionality downtime working with oracle support.

I’m not saying that the clause is useless. All i’m saying is that the term appears very innocent for the risk involved and doesnt caution its usage and also the risk associated is not properly documented.

This is from the 11g Release 2 Database Administrators Guide – Not a peep in it

Removing Unused Columns
The ALTER TABLE…DROP UNUSED COLUMNS statement is the only action allowed
on unused columns. It physically removes unused columns from the table and
reclaims disk space.

In the ALTER TABLE statement that follows, the optional clause CHECKPOINT is
specified. This clause causes a checkpoint to be applied after processing the specified
number of rows, in this case 250. Checkpointing cuts down on the amount of undo
logs accumulated during the drop column operation to avoid a potential exhaustion of
undo space.

ALTER TABLE hr.admin_emp DROP UNUSED COLUMNS CHECKPOINT 250;

Ofcourse the 11g Release 2 SQL Language Reference Guide mentions it

DROP UNUSED COLUMNS Clause

CHECKPOINT Specify CHECKPOINT if you want Oracle Database to apply a
checkpoint for the DROP COLUMN operation after processing integer rows; integer
is optional and must be greater than zero. If integer is greater than the number of
rows in the table, then the database applies a checkpoint after all the rows have been
processed. If you do not specify integer, then the database sets the default of 512.
Checkpointing cuts down the amount of undo logs accumulated during the DROP
COLUMN operation to avoid running out of undo space. However, if this statement is
interrupted after a checkpoint has been applied, then the table remains in an unusable
state. While the table is unusable, the only operations allowed on it are DROP TABLE,
TRUNCATE TABLE, and ALTER TABLE DROP … COLUMNS CONTINUE (described in
sections that follow).
You cannot use this clause with SET UNUSED, because that clause does not remove
column data.

I feel that this caution should be mentioned in the Administrators Guide and that too in bold.
I would raise a Documentation bug

February 18, 2011

Calculate iops for a database instance

Filed under: Uncategorized — srivenu @ 9:26 pm

This blog entry is about the method i normally use to estimate the iops for a currently operational database instance.
There was a SIEBEL database at a client site that was presently running on a 2 node RAC (10.2.0.4) with SUN Cluster and QFS. A high level decision has been made to move the database to a new storage and to ASM. I was asked to provide the IO load of the existing database so that the new storage could be provisioned. AWR in that database was scheduled to run every 15 minutes.

I used the following sql to get the data from AWR.

define  name='physical read total IO requests'
define inst_no=1
define slotsize=900
define rangesize=500
define start_peak_hour=8
define end_peak_hour=15

col range head "   IOPS Range" form a20
col noofslots head "No Of|Occurences" form 999,999


select	lpad(trunc(vpersec/&rangesize) * &rangesize, 6) ||' - '||
	lpad(((trunc(vpersec/&rangesize) + 1) * &rangesize) - 1, 6) range,
	sum(noofslots) noofslots
from	(
	select	st/(extract(DAY from (dest - dsst)) * 86400 + extract(HOUR from (dest - dsst)) * 3600+ 
		extract(MINUTE from (dest - dsst)) * 60+ extract(SECOND from (dest - dsst))) vpersec,
		round((extract(DAY from (dest - dsst)) * 86400 + extract(HOUR from (dest - dsst)) * 3600+ 
		extract(MINUTE from (dest - dsst)) * 60+ extract(SECOND from (dest - dsst)))/&slotsize) noofslots 
	from	(
		select 	/*+ full(st) full(ss) use_hash(st)*/
			to_char(ss.BEGIN_INTERVAL_TIME,'DAY DD-MM-YYYY HH24:MI:SS') est, 
			lag(to_char(ss.BEGIN_INTERVAL_TIME,'DAY DD-MM-YYYY HH24:MI:SS')) 
			over(order by ss.snap_id) sst,
			ss.BEGIN_INTERVAL_TIME dest,
			lag(ss.BEGIN_INTERVAL_TIME) over(order by ss.snap_id) dsst,
			st.value-lag(st.value,1,0) over(order by ss.snap_id) st
		from 	sys.WRH$_SYSSTAT 	st,
			sys.WRM$_SNAPSHOT 	ss
		where 	st.snap_id=ss.snap_id
		and	ss.INSTANCE_NUMBER = &inst_no
		and	st.INSTANCE_NUMBER = &inst_no
		and	ss.dbid=st.dbid
		and	st.stat_id in (
			select	stat_id
			from	v$statname
			where	upper(name)=upper(trim('&name'))
			)
		and 	ss.snap_id in (
			select 	/*+push_subq*/
				snap_id
			from 	sys.WRM$_SNAPSHOT 
			where	INSTANCE_NUMBER = &inst_no
			and	to_char(BEGIN_INTERVAL_TIME, 'HH24') between &start_peak_hour and &end_peak_hour
	   		) 
		)
	where   sst is not null
	and	st > 0
	and	to_char(to_date(sst, 'DAY DD-MM-YYYY HH24:MI:SS'),'dd-mon-yy') 
		= to_char(to_date(est, 'DAY DD-MM-YYYY HH24:MI:SS'),'dd-mon-yy')
	)
group	by lpad(trunc(vpersec/&rangesize) * &rangesize, 6) ||' - '||
	lpad(((trunc(vpersec/&rangesize) + 1) * &rangesize) - 1, 6)
order	by lpad(trunc(vpersec/&rangesize) * &rangesize, 6) ||' - '||
	lpad(((trunc(vpersec/&rangesize) + 1) * &rangesize) - 1, 6)
/

The peak hours were defined by the client as between 8AM and 3PM. Each snap of 900 seconds is considered as 1 slot. Sometimes a snap might have missed out or sometimes a manual snap might have been taken between a regular 15 minute slot. The sql would handle such cases.


For Write iops, we run the above sql by redifining name
define  name='physical write total IO requests'

For redo writes, we run the sql by redefining name
define  name='redo writes'

If the AWR snaps are scheduled every 1 hour and the peak times are 10AM to 6PM, we can run this sql with these defined values.

define slotsize=3600
define start_peak_hour=10
define end_peak_hour=18

Consider this sample data from one of our instances

*******************************
physical read total IO requests
*******************************

                          No Of
   IOPS Range        Occurences
-------------------- ----------
  2000 -   2499              41
  2500 -   2999              84
  3000 -   3499              57
  3500 -   3999              29
  4000 -   4499               9
  4500 -   4999               5
  5000 -   5499               2
  5500 -   5999               2


*******************************
physical read write IO requests
*******************************

                          No Of
   IOPS Range        Occurences
-------------------- ----------
     0 -    499              75
   500 -    999             147
  1000 -   1499               4
  1500 -   1999               2
  2000 -   2499               1


***********
redo writes
***********


                          No Of
   IOPS Range        Occurences
-------------------- ----------
     0 -    499             229

Interpreting data from a single instance database is a bit easier. I would consider the less than 1% occurences as abnormalities that could be ignored. From above data, i would consider the read IOPS to be 5000. I would consider the 2 occurences each between “5000 – 5499” and “5500 – 5999” as abnormalities and ignore them. Using similar logic, i would consider writes to be 1500 (or 2000 for safety margin) and redo writes to be 500. To be cautious, we could look at the snap intervals, corresponding to the abnormal data, in more detail to discern the cause.

But things get a little more complicated when we have RAC.
Consider this from one of our 2-Node RAC instances.


*******************************
physical read total IO requests
*******************************

Node 1

                          No Of
   IOPS Range        Occurences
-------------------- ----------
  2000 -   2499              41
  2500 -   2999              84
  3000 -   3499              57
  3500 -   3999              29
  4000 -   4499               9
  4500 -   4999               5
  5000 -   5499               2
  5500 -   5999               2


Node 2


                          No Of
   IOPS Range        Occurences
-------------------- ----------
  1500 -   1999               4
  2000 -   2499              40
  2500 -   2999              69
  3000 -   3499              36
  3500 -   3999              20
  4500 -   4999               4
  5000 -   5499               2
  6500 -   6999               1
  7000 -   7499               2
  7500 -   7999               2


*******************************
physical read write IO requests
*******************************


Node 1

                          No Of
   IOPS Range        Occurences
-------------------- ----------
     0 -    499              75
   500 -    999             147
  1000 -   1499               4
  1500 -   1999               2
  2000 -   2499               1


Node 2

                          No Of
   IOPS Range        Occurences
-------------------- ----------
     0 -    499              77
   500 -    999              95
  1000 -   1499               5
  1500 -   1999               2
  2000 -   2499               1



***********
redo writes
***********

Node 1

                          No Of
   IOPS Range        Occurences
-------------------- ----------
     0 -    499             229


Node 2


                          No Of
   IOPS Range        Occurences
-------------------- ----------
     0 -    499             180

Now what should we take the read IOPS to be for the whole database?
I would consider Node 1 max as 5000 and Node 2 max as 5000. So should i just add them up? That would mean assuming that both nodes peak at the same time and might lead to overestimation of the IOPS at the database level.
I would blog about that calculation in a seperate post.

February 15, 2011

One way to detect JDBC connection leaks

Filed under: Uncategorized — srivenu @ 8:21 am

I just wanted to blog about a connect leak issue that i had encountered in a in-house developed, Email center application. The application was developed using struts and commons pool. After some code and configuration changes, the application started facing performance issues and was hanging after 1-2 days of app server startup. The workaround was to restart the app server.
The error_log during the period showed the following message “oc4j_socket_recvfull timed out”.
The java thread during the hang dump showed several threads with the following state
(I had renamed our code names with xyz.abc)

"AJPRequestHandler-RMICallHandler-231" prio=1 tid=0x0849e0c8 nid=0x5d3c in Object.wait() [0x58925000..0x58925da0]
	at java.lang.Object.wait(Native Method)
	- waiting on  (a org.apache.commons.pool.impl.GenericObjectPool)
	at java.lang.Object.wait(Object.java:474)
	at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:810)
	- locked  (a org.apache.commons.pool.impl.GenericObjectPool)
	at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:96)
	at org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:880)
	at com.xyz.abc.dao.SummaryCount.mailsInQueue(SummaryCount.java:356)
	at com.xyz.abc.actions.MailInQueAction.execute(MailInQueAction.java:36)
	at org.apache.struts.action.RequestProcessor.processActionPerform(RequestProcessor.java:484)
	at org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:274)
	at org.apache.struts.action.ActionServlet.process(ActionServlet.java:1482)
	at org.apache.struts.action.ActionServlet.doPost(ActionServlet.java:525)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:763)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:856)
	at com.evermind.server.http.ResourceFilterChain.doFilter(ResourceFilterChain.java:64)
	at com.xyz.abc.utils.EmcSecurityFilter.doFilter(EmcSecurityFilter.java:152)
	at com.evermind.server.http.ServletRequestDispatcher.invoke(ServletRequestDispatcher.java:644)
	at com.evermind.server.http.ServletRequestDispatcher.forwardInternal(ServletRequestDispatcher.java:391)
	at com.evermind.server.http.HttpRequestHandler.doProcessRequest(HttpRequestHandler.java:908)
	at com.evermind.server.http.HttpRequestHandler.processRequest(HttpRequestHandler.java:458)
	at com.evermind.server.http.AJPRequestHandler.run(AJPRequestHandler.java:313)
	at com.evermind.server.http.AJPRequestHandler.run(AJPRequestHandler.java:199)
	at oracle.oc4j.network.ServerSocketReadHandler$SafeRunnable.run(ServerSocketReadHandler.java:260)
	at oracle.oc4j.network.ServerSocketAcceptHandler.procClientSocket(ServerSocketAcceptHandler.java:234)
	at oracle.oc4j.network.ServerSocketAcceptHandler.access$700(ServerSocketAcceptHandler.java:29)
	at oracle.oc4j.network.ServerSocketAcceptHandler$AcceptHandlerHorse.run(ServerSocketAcceptHandler.java:879)
	at com.evermind.util.ReleasableResourcePooledExecutor$MyWorker.run(ReleasableResourcePooledExecutor.java:303)
	at java.lang.Thread.run(Thread.java:595)

After seeing the error message, i thought i would monitor the open database connections for this application.

select 	count(*)
from 	v$session
where 	username = 'ABCD'
and 	machine = 'XYZ'
and 	program = 'JDBC Thin Client'
/

After monitoring this output for sometime, i could see a steady increase in the number of open connections. This clearly pointed out to a connection leak in the code.
The next logical step was to identify the offending piece of code and fix it. The developers have informed that they had already done several thorough checks of their code. They were also sceptical that the issue was due to a bug in the commons pool and wanted to use a different pool. I could understand their problem as the code was huge and ran into thousands of lines. It wouldnt be practically feasible to identify the culprit unless the search was somehow narrowed down.

I used the following method to help the developers in narrowing down their search operation for a connection leak. My thought was that if there is a connection leak, then the PREV_HASH_VALUE (it was 8i hence no SQL_ID) of the sessions (corresponding to leaked connections) would point out the last sql that was executed before the connection object went out of scope in the java application. So i used the following sql to get the last sql’s executed by the sessions

col sid head "Sid" form 9999 trunc
col serial# form 99999 trunc head "Ser#"
col username form a15 trunc
col machine head "Client|Machine" form a20 trunc
col login head "Login" form a11
col sql_hash_value head "Curr|Hash|Value" form 9999999999
col prev_hash_value head "Prev|Hash|Value" form 9999999999
col "last call"  form 9999999 trunc head "Last Call|In Secs"
col status form a6 trunc

select	sid, serial#, username, machine,
        to_char(logon_time,'ddMon hh24:mi') login,
        SQL_HASH_VALUE, PREV_HASH_VALUE,
        last_call_et "last call", status
from 	v$session
where 	username = 'ABCD'
and 	machine = 'XYZ'
and 	program = 'JDBC Thin Client'
order 	by logon_time
/

The output was something like this


                                                                     Curr        Prev
                             Client                                  Hash        Hash Last Call
  Sid   Ser# Username        Machine              Login             Value       Value   In Secs STATUS
----- ------ --------------- -------------------- ----------- ----------- ----------- --------- ------
 1386  13316 ABCD            machin11             15Sep 14:52           0  1836767206      1563 INACTI
 3168  12144 ABCD            machin11             15Sep 14:53           0  1836767206      1561 INACTI
 5718   7638 ABCD            machin11             15Sep 14:53           0  1836767206      1571 INACTI
 4312   9851 ABCD            machin11             15Sep 14:54           0  1836767206      1578 INACTI
 5512   9858 ABCD            machin11             15Sep 14:54           0  1836767206      2262 INACTI
 1988  11653 ABCD            machin11             15Sep 14:55           0  1836767206      2130 INACTI
 6924    314 ABCD            machin11             15Sep 14:55           0  1836767206      2142 INACTI
 3515   7286 ABCD            machin11             15Sep 14:57           0  1836767206      1281 INACTI
 6633   3135 ABCD            machin11             15Sep 14:57           0  1836767206      1520 INACTI

There were hundreds of sessions which pointed out to the same hash_value “1836767206”.
I gathered the sql_text for this hash_value and the developers said that i came from a DAO.
Seeing where this DAO is accessed from and searching nearby, we could quickly catch the culprit! By mistake, a new connection object is being obtained on the same connection variable, without releasing it first, thereby making the old connection go out of scope.

Thought this blog entry might help others in trying to debug database connection leak issues.

Blog at WordPress.com.