Wednesday, December 21, 2011

Implicit conversion of a character string to Oracle DATE type is dangerous

Typically TO_DATE function is used by taking a char as the first argument and 'fmt' as the second argument. According to Oracle doc:

TO_DATE converts char of CHAR, VARCHAR2, NCHAR, or NVARCHAR2 datatype to a value of DATE datatype. The fmt is a datetime model format specifying the format of char. If you omit fmt, then char must be in the default date format. If fmt is J, for Julian, then char must be an integer.

It should be pointed out that omitting the fmt could be a very bad practise. If the character string does not match the default format, Oracle does not necessarily throw error in some cases. For example, I have executed the following commands in the SQL* Plus:
SQL>alter session set nls_date_format='yyyy-mm-dd HH24:mi:ss';

Session altered.


SQL>select count(*) from  dba_objects where created between '1-Nov-2011' and '14-Nov-2011';

  COUNT(*)
----------
         0

1 row selected.

SQL>select to_date('1-Nov-2011') from dual;

TO_DATE('1-NOV-2011
-------------------
0001-11-20 11:00:00

1 row selected.



While the correct results should be as follows:



SQL>alter session set nls_date_format='dd-Mon-yyyy HH24:mi:ss';

Session altered.

SQL>select count(*) from  dba_objects where created between '1-Nov-2011' and '14-Nov-2011';

  COUNT(*)
----------
       171

1 row selected.

SQL>select to_date('1-Nov-2011') from dual;

TO_DATE('1-NOV-2011'
--------------------
01-Nov-2011 00:00:00

1 row selected.



I have learned this in a pretty hard way during a sql tuning effort. Many hours have been spent before I realized that the weired results were due to this implicit conversion "bug". ( See http://www.freelists.org/post/oracle-l/Huge-difference-between-sqlplus-and-sqldeveloper-sorting-in-memory-vs-disk,7)

Sunday, November 27, 2011

Reorganize Table and Index

I manage a database for the retail ordering application. The orders that were completed 90 days ago are subject to archiving. Due to various reasons there were about 80 million archiving backlog about two months ago. Since the backlog is caught up now, reorganization of the schema objects is desirable in order to reclaim space.

First of all, I need to estimate how much space can be saved potentially after the reorganization. For table segment, I use DBMS_SPACE.create_table_cost to estimate the size after reorganization. Given the number of row and average row size and the target tablespace, the following script can be used to estimate the size if the table is moved to the target tablespace.

--  script: tabsize_est.sql 
--  get the avg row size and row cnt from analyze job
--  dba_tables
-- @tabsize_est 'table_size' 100   10000000

set verify off feedback off
set SERVEROUTPUT ON
DECLARE
  l_ddl          VARCHAR2(500);
  l_used_bytes   NUMBER;
  l_alloc_bytes  NUMBER;
  l_message      varchar2(100);
BEGIN
  -- Estimate the size of a new table on the USERS tablespace.
  l_message := '&1';
  DBMS_SPACE.create_table_cost (
            tablespace_name => 'TTQ_ORD_DATA_4',
            avg_row_size    => &2,
            row_count       => &3 ,
            pct_free        => 10 ,
            used_bytes      => l_used_bytes,
            alloc_bytes     => l_alloc_bytes);

  DBMS_OUTPUT.put_line (  l_message  || ' Mbytes_allocated= ' || l_alloc_bytes/1024/1024 || ' Mbytes');
END;
/


I use the following script to generate command for each table:

--  script: tabsize_est_gen.sql
--  purpose: generate 
select '@@tabsize_est ' ||''' ' || t.owner || ' ' || t.table_name || ' ' || t.tablespace_name || ' ' 
     || trunc(s.bytes/1024/1024)  || ''' '||  t.avg_row_len || ' ' || t.num_rows
from
dba_segments s,
dba_tables t
where s.owner=t.owner
and  s.segment_name=t.table_name
and t.owner in  ('TTQ_ORD')
and  s.bytes > 1000000000
/



The output from above script looks like:

@@tabsize_est ' TTQ_ORD CUST_ORDER_ACTIVITY TTQ_ORD_DATA_2 2611' 139 15874503
@@tabsize_est ' TTQ_ORD CUST_HIGH_RISK_20110425 TTQ_ORD_DATA_2 1349' 82 14246227
@@tabsize_est ' TTQ_ORD ENCDEC_MIGRATION TTQ_ORD_DATA_4 1400' 29 2257790
@@tabsize_est ' TTQ_ORD ACCOUNT_COMMENTS TTQ_ORD_DATA_4 13600' 146 82486887
@@tabsize_est ' TTQ_ORD BUNDLE_RECON_TRACKING TTQ_ORD_DATA_3 7060' 957 6294040
@@tabsize_est ' TTQ_ORD ISP_MESSAGE_TRACKING TTQ_ORD_DATA_3 30480' 815 31089530
...

Then, executing above commands, I can obtain current and estimated table segment size as shown below:

TTQ_ORD CUST_ORDER_ACTIVITY TTQ_ORD_DATA_2 2611 Mbytes_allocated= 2600 Mbytes
TTQ_ORD CUST_HIGH_RISK_20110425 TTQ_ORD_DATA_2 1349 Mbytes_allocated= 1400 Mbytes
TTQ_ORD ENCDEC_MIGRATION TTQ_ORD_DATA_4 1400 Mbytes_allocated= 200 Mbytes
TTQ_ORD ACCOUNT_COMMENTS TTQ_ORD_DATA_4 13600 Mbytes_allocated= 13600 Mbytes
TTQ_ORD BUNDLE_RECON_TRACKING TTQ_ORD_DATA_3 7060 Mbytes_allocated= 7200 Mbytes
TTQ_ORD ISP_MESSAGE_TRACKING TTQ_ORD_DATA_3 30480 Mbytes_allocated= 30400 Mbytes
...

To estimate the size of index segment after rebuild, I use a script called index_est_proc_2.sql by Joanathan Lewis (http://jonathanlewis.wordpress.com/index-sizing/).

I use EXCEL to calcuate the size difference between the estimated size and current size for each index and table. As a result I can estimate the total space gain. Of course when I plan to do reoraganization, I can start with the segment which would give the most space gain.

The space gain estimated is at tabespace level. To actually release the space at OS level, the datafile needs to be shrinked. For this it is very useful to know which segments reside at the end of datafile. Those segments should be moved first to allow the datafile shrikable.

The following script is used to list the segment in each data file ordered by its max(block_id). The segments that reside at the end of datafile should have large max(block_id).


-- find segment at the end of the data files
-- so if this segment is removed, the data file could be resized down

spool shrinkdf_&tbs..log

col sum_mbytes format 999,999
col  diff format 999,999,999

select name from v$database;

break on file_id skip 1
select file_id, segment_name, sum_mbytes, count_blocks, max_block_id, 
max_block_id -  lead(max_block_id,1) over (partition by file_id order by max_block_id desc )  diff
from
(
select /*+ RULE */ 
file_id
, segment_name
, sum(bytes/1014/1024)  sum_mbytes
, count(block_id) count_blocks
, max(block_id) max_block_id
from dba_extents
where tablespace_name = upper('&&tbs') 
group by file_id, segment_name
order by 1, 5 desc,4
)
/

spool off

undef tbs


Sample outout from the above script looks like:

FILE_ID SEGMENT_NAME                   SUM_MBYTES COUNT_BLOCKS MAX_BLOCK_ID         DIFF
---------- ------------------------------ ---------- ------------ ------------ ------------
       227 ORDER_TRANS                         1,818            9      1868809      128,000
           AUDIT_TRAIL                         1,010            5      1740809       25,600
           ORD_ADDRESS                           808            4      1715209       51,200
           MASTER_ACCOUNT                        202            1      1664009      179,200
           ORD_TRANS_DETAILED_STATUS             202            1      1484809       51,200
           ORDER_MASTER                          202            1      1433609      153,600
           MASTER_SERVICE                        202            1      1280009       25,600
           ACCOUNT_HISTORY                       202            1      1254409       25,600
           ACCOUNT_COMMENTS                      202            1      1228809       51,200
           ORD_ACCOUNT                           202            1      1177609       51,200
           SUPP_HISTORY                          202            1      1126409      102,400
           CREDIT_CHECK                          202            1      1024009      153,600
           ORD_CONTACT                           404            2       870409       25,600
           ORD_TRANS_NOTES_HISTORY               404            2       844809      102,400
           ORD_DSL                               404            2       742409



It is clear that for the datafile with file_id=227, ORDER_TRANS is at the end, followed by AUDIT_TRAIL.

Finally, the following script can be used to generate the resize statement:


rem  script: red_df.sql 
rem 
rem  Purpose: This gives the Total size of datafiles in a tablespace
rem         and also the size to which it can be reduced.
rem     It generated rdf.log spool file with commands to resize datafiles
rem  Usage: @red_df.sql <TABLESPACE>
rem 
rem  Note: I got this script from a colleague but I once saw this script in AskTom website 

set verify off

col tsname  format         a24    justify c heading 'Tablespace'
col nfrags  format     9,999,990  justify c heading 'Free|Frags'
col mxfrag  format   999,990.999  justify c heading 'Largest|Free Frag'
col totsiz  format 9,999,990.999  justify c heading 'Total|Mbytes'
col avasiz  format 9,999,990.999  justify c heading 'Available|Mbytes'
col pctusd  format       990.99   justify c heading 'Percent|Used'

set pagesize 200
set linesize 120

select
total.tablespace_name                       tsname,
count(free.bytes)                           nfrags,
round(nvl(max(free.bytes)/1048576,0),2)              mxfrag,
total.bytes/1048576                         totsiz,
round(nvl(sum(free.bytes)/1048576,0),2)              avasiz,
round((1-nvl(sum(free.bytes),0)/total.bytes)*100,2)  pctusd
from
(select tablespace_name, sum(bytes) bytes
from dba_data_files
where tablespace_name = upper('&1')
group by tablespace_name)  total,
dba_free_space  free
where
total.tablespace_name = free.tablespace_name(+)
and total.tablespace_name = upper('&1')
group by
total.tablespace_name,
total.bytes;


set verify off
set linesize 150
set echo off

column file_name format a60 word_wrapped
column smallest format 999,990 heading "Smallest|Size|Poss."
column currsize format 999,990 heading "Current|Size"
column savings format 999,990 heading "Poss.|Savings" 
break on report
compute sum of savings on report

column value new_val blksize
select value from v$parameter where name = 'db_block_size'
/

select file_name,
ceil( (nvl(hwm,1)*&&blksize)/1024/1024 ) smallest, 
ceil( blocks*&&blksize/1024/1024) currsize,
ceil( blocks*&&blksize/1024/1024) -
ceil( (nvl(hwm,1)*&&blksize)/1024/1024 ) savings
from dba_data_files a,
( select file_id, max(block_id+blocks-1) hwm 
from dba_extents
group by file_id ) b
where a.file_id = b.file_id(+)
and a.tablespace_name = upper('&1')
/

spool rdf.log
column cmd format a75 word_wrapped
set pagesize 4000

select 'alter database datafile '''||file_name||''' resize ' ||
ceil( (nvl(hwm,1)*&&blksize)/1024/1024 ) || 'm;' cmd 
from dba_data_files a,
( select file_id, max(block_id+blocks-1) hwm
from dba_extents
group by file_id ) b
where a.file_id = b.file_id(+)
and ceil( blocks*&&blksize/1024/1024) - 
ceil( (nvl(hwm,1)*&&blksize)/1024/1024 ) > 0
and a.tablespace_name = upper('&1')
/
spool off

Monday, November 07, 2011

Cloud Computing and DBA career

Recently, in reply to a question in the MITBBS database forum( in Chinese) –“Will the DBA career become down-hill and the future dimmed with the growth of Cloud Computing and NoSQL movement ?”, I made the following comments:


My understanding till today: NOSQL is just a special purpose database (or data model), it cannot replace traditional general purpose RDBMS. (The market of NoSQL is small). It has little impact on DBA’s career.


Cloud computing provides more choices for a company for its IT infrastructure. Basically three choices: traditional in-house IT; outsource IT totally ( i.e. to public cloud provider, pay-per-use ); consolidating in house IT infrastructure on private cloud; or maybe the fourth choice, some kind of mixing of all above. I think the demanding for DBA role (or system admin, network, storage admin in this regard) will be reduced when a company move part (or all) of its IT to cloud (either public or private).


Demanding for traditional DBA role is not only being affected by emerging of cloud computing. It has been affected by more and more self-managing and automation of RDBMS anyway ( In USA that role is being outsourced to India and China etc)


Obviously if there is a trend to move to cloud with significance, there will be a demanding for “cloud system/support administrator” It should not so difficult for a true DBA ( means he is always willing to learn new things) to transition his role to a cloud administrator.


After making the comments, I googled more and found the following article interesting: “The tech jobs that the cloud will eliminate” ( http://www.infoworld.com/d/adventures-in-it/tech-jobs-cloud-will-eliminate-008 ). There is also a two-part article describing Cloud IT roles here: http://open.eucalyptus.com/learn/cloud-it-roles. It indicated a DBA’s skill-set is extendable to assume Cloud Data Architect role.

I wrote a Perl script to non-interactively search dice.com to get the count of job listing with respect to some keywords. I scheduled to do this count every day. Hope this will give me some kind of insights into the trend about the DBA job market and the impact by Cloud Computing.

For example, the output of the script of yesterday looked like:

2011-11-06 07:59 System+Administrator 5688
2011-11-06 07:59 DBA 2799
2011-11-06 07:59 Oracle+DBA 1570
2011-11-06 07:59 Cloud+Administrator 277
2011-11-06 07:59 Cloud+DBA 74

Wednesday, October 12, 2011

SQL Server - Find out Transactions per second etc from DM_OS_PERFORMANCE_COUNTERS

In a whitepaper named "Diagnosing and Resolving Latch Contention on SQL Server",  a script is provided to snap DM_OS_WAITE_STATS view to calculate wait over a period of time. In this post, based on the same idea,  I developed a script to snap the DM_OS_PERFORMANCE_COUNTERS view in order to find out transactions/sec for each database. It is also easy to be modified to get other performance counters.


-- script: snap_perf_conuter.sql

/* Snapshot the performance counters (such as transaction/sec) on sys.dm_os_performance_counters
   and store in a table so that they can be used to compute a per second value.
      This script is only applicable to Cntr_Type = 272696576. Different Cntr_type is explained
      in this blog:
        http://rtpsqlguy.wordpress.com/2009/08/11/sys-dm_os_performance_counters-explained/
** Data is maintained in tempdb so the connection must persist between each execution** 
**alternatively this could be modified to use a persisted table in tempdb. if that is changed code should be included to clean up the table at some point.**
 */


use tempdb
go
declare @current_snap_time datetime
declare @previous_snap_time datetime
-- declare @l_counter_name  nchar(128)
declare @sqlcmd nvarchar(4000)
declare @l_counter_name  nvarchar(2000)

-- modify the counter_name as needed, some examples provided 
set @l_counter_name  = '''transactions/sec'''
-- set @l_counter_name = '''Batch Requests/sec'''                                                                                                              
-- set @l_counter_name= '''Page Splits/sec'',''Page lookups/sec'''
-- set @l_counter_name = '''transactions/sec'',''Batch Requests/sec'''                                                                                                              
-- set @l_counter_name='''Page compression attempts/sec'',''Page Deallocations/sec'',''Page lookups/sec'',''Page reads/sec'',''Page Splits/sec'',''Page writes/sec'',''Pages Allocated/sec'',''Pages compressed/sec'''
-- set @l_counter_name = '''Logins/sec'',''Logouts/sec'''                                                                                              



if not exists(select name from tempdb.sys.sysobjects where name like '#_perf_counter%') 
create table #_perf_counter ( "object_name" nchar(128) ,counter_name nchar(128) ,instance_name nchar(128) ,cntr_value bigint ,cntr_type int ,snap_time datetime
)

set @sqlcmd ='
insert into #_perf_counter (
object_name
,counter_name
,instance_name
,cntr_value
,cntr_type
,snap_time
)
select
OBJECT_NAME
,counter_name
,instance_name
,cntr_value
,cntr_type
,getdate()
from sys.dm_os_performance_counters
where counter_name in (' +  @l_counter_name +  ')'

exec sp_executesql @sqlcmd

--get the previous and current collection point
select top 1 @previous_snap_time = snap_time from #_perf_counter where snap_time < (select max(snap_time) from #_perf_counter) order by snap_time desc

select @current_snap_time = max(snap_time) from #_perf_counter

-- debug
select @current_snap_time end_time, @previous_snap_time start_time

set @sqlcmd='
select
e.object_name
,e.counter_name
,e.instance_name
,(e.cntr_value -s.cntr_value) / DATEDIFF(ss, s.snap_time, e.snap_time)  Per_Sec_Value 
--, s.snap_time as [start_time] 
--, e.snap_time as [end_time] , DATEDIFF(ss, s.snap_time, e.snap_time) as [seconds_in_sample] from #_perf_counter e inner join  
( select * from #_perf_counter   
where snap_time ='''+ convert(varchar(100), @previous_snap_time, 21) + ''' ) s on ( e.instance_name=s.instance_name and e.object_name = s.object_name and e.instance_name=s.instance_name 
   and e.counter_name=s.counter_name)
where e.snap_time= '''+  convert(varchar(100), @current_snap_time, 21) + ''' and e.counter_name in (' +  @l_counter_name + ')order by Per_Sec_value desc'


exec sp_executesql @sqlcmd

--clean up table
 delete from #_perf_counter
 where snap_time = @previous_snap_time

-----------------  end of script  ----

Sample output (edited) :
end_time                start_time
----------------------- -----------------------
2011-10-12 18:47:25.173 2011-10-12 18:46:23.190

(1 row(s) affected)

object_name                         counter_name     instance_name               Per_Sec_Value        seconds_in_sample
----------------------------------- ---------------- --------------------------- -------------------- -----------------
MSSQL$FPSEFSDB_OP2:Databases        Transactions     _Total                      296                  62
MSSQL$FPSEFSDB_OP2:Databases        Transactions     tempdb                      126                  62
MSSQL$FPSEFSDB_OP2:Databases        Transactions     Orderplacement              100                  62
MSSQL$FPSEFSDB_OP2:Databases        Transactions     master                      60                   62
MSSQL$FPSEFSDB_OP2:Databases        Transactions     Distributor                 2                    62
MSSQL$FPSEFSDB_OP2:Databases        Transactions     NOCVDB                      1                    62
MSSQL$FPSEFSDB_OP2:Databases        Transactions     DBADB                       1                    62
MSSQL$FPSEFSDB_OP2:Databases        Transactions     msdb                        1                    62
MSSQL$FPSEFSDB_OP2:Databases        Transactions     tempdbx                     0                    62
MSSQL$FPSEFSDB_OP2:Databases        Transactions     spot_admin                  0                    62
MSSQL$FPSEFSDB_OP2:Databases        Transactions     ASPState                    0                    62
MSSQL$FPSEFSDB_OP2:Databases        Transactions     APPCACHELOG                 0                    62
MSSQL$FPSEFSDB_OP2:Databases        Transactions     VGISessions                 0                    62
MSSQL$FPSEFSDB_OP2:Databases        Transactions     SSNSDB                      0                    62
MSSQL$FPSEFSDB_OP2:Databases        Transactions     SSNS4DB                     0                    62
MSSQL$FPSEFSDB_OP2:Databases        Transactions     copper                      0                    62
MSSQL$FPSEFSDB_OP2:Databases        Transactions     VZWPCAT                     0                    62
MSSQL$FPSEFSDB_OP2:Databases        Transactions     model                       0                    62
MSSQL$FPSEFSDB_OP2:Databases        Transactions     mssqlsystemresource         0                    62

Saturday, October 08, 2011

SQL Server - Troubleshooting Deadlock

There is a thread  in the SQLTeam forum that describes a deadlock scenario:
The application inserts a row into a status table. A trigger on the table fires so that when the status id inserted is a certain value it will call a stored procedure, which inserts a row into an accounting table. This whole thing is wrapped in a transaction so it should all be getting rolled back when there are errors. On occasion two threads of the application insert into the status table at nearly the same millisecond, and when both end up calling the stored procedure to insert into the accounting table a deadlock occurs and one is killed.

Two important details were unveiled during the discussion:
(1) the whole transaction took place with isolation level set to be serializable
(2) in the stored procedure, there is an existence check query doing full table scan  on the status table before inserting the row into it.

I try to simulate the deadlock situation for my own better understanding, especially this is the first time I know how to use DBCC trace to troubleshooting deadlock. It is a good practise.

First of all, I created the following test table:


-- create a test table

USE testdata
go

IF OBJECT_ID ( 'mytable', 'U' ) IS NOT NULL
DROP TABLE mytable;
GO


CREATE TABLE mytable
 (
  id  INT,
  val INT,
  padding VARCHAR(4000),
  );

create unique clustered index index01
on mytable(id);

INSERT INTO mytable
SELECT 1, 1, REPLICATE('a', 4000);

INSERT INTO mytable
SELECT 2, 2, REPLICATE('a', 4000);

INSERT INTO mytable
SELECT 3, 3, REPLICATE('a', 4000);

INSERT INTO mytable
SELECT 4, 4, REPLICATE('a', 4000);

go

delete from mytable where id in (2,4);

-- show the location of rows
select
       a.%%physloc%%                          AS Address,
       sys.fn_PhysLocFormatter(a.%%physloc%%) AS AddressText,
       a.id
FROM   mytable a
ORDER BY 2;
go


The remaining two rows in the mytable are located in different page as shown below:

Address    AddressText            id
---------- ---------------------- -----------
0x99000000 (1:153:0)                        1
0xFF420000 (1:17151:0)                      3

Secondly I turn on the deadlock trace:

1> DBCC traceon(1222, -1)
2> go
DBCC execution completed. If DBCC printed error messages, contact your system administrator.


Then I run the following two scripts in two different SSMS windows:


-- script: ins_1.sql 
use testdata
go

set transaction isolation level serializable
begin tran
go
if not exists (select id from mytable where val = 2)
begin
  waitfor delay '00:01:00'
  insert into mytable values (2,2, replicate('a','4000'))
end
go
commit tran
go

-- script: ins_2.sql
use testdata
go

set transaction isolation level serializable
begin tran
go
if not exists (select id from mytable where val = 4)
begin
  waitfor delay '00:01:00'
  insert into mytable values (4,4, replicate('a','4000'))
end
go
commit tran
go







Withing the 1 min delay, run sp_lock procedure, I can see the key-range locks are requested by the two sessions:

spid   dbid   ObjId       IndId  Type Resource                         Mode     Status
------ ------ ----------- ------ ---- -------------------------------- -------- ------
53     8      0           0      DB                                    S        GRANT
52     8      0           0      DB                                    S        GRANT
52     8      0           0      MD   49(90c8bd04:fb81833:777569)      Sch-S    GRANT
53     8      0           0      MD   49(ead7fb30:916efee:7da7e5)      Sch-S    GRANT
53     8      66099276    1      PAG  1:153                            IS       GRANT
52     8      66099276    1      PAG  1:153                            IS       GRANT
53     8      66099276    1      PAG  1:17151                          IS       GRANT
52     8      66099276    1      PAG  1:17151                          IS       GRANT
53     8      66099276    0      TAB                                   IS       GRANT
52     8      66099276    0      TAB                                   IS       GRANT
53     8      66099276    1      KEY  (ffffffffffff)                   RangeS-S GRANT
52     8      66099276    1      KEY  (ffffffffffff)                   RangeS-S GRANT
53     8      66099276    1      KEY  (03000d8f0ecc)                   RangeS-S GRANT
52     8      66099276    1      KEY  (03000d8f0ecc)                   RangeS-S GRANT
53     8      66099276    1      KEY  (010086470766)                   RangeS-S GRANT
52     8      66099276    1      KEY  (010086470766)                   RangeS-S GRANT



Key-range locks protect a range of rows implicitly included in a record set being read by a Transact-SQL statement while using the serializable transaction isolation level. The serializable isolation level requires that any query executed during a transaction must obtain the same set of rows every time it is executed during the transaction. A key range lock protects this requirement by preventing other transactions from inserting new rows whose keys would fall in the range of keys read by the serializable transaction.


After about 1 min, one of the sessions received the following message:

Msg 1205, Level 13, State 48, Line 4
Transaction (Process ID 52) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
Msg 3902, Level 16, State 1, Line 1
The COMMIT TRANSACTION request has no corresponding BEGIN TRANSACTION.


In the error log, I can find the following:
--------------------- start of error log  ------------------

2011-10-08 11:01:06.38 spid55      DBCC TRACEON 1222, server process ID (SPID) 55. This is an informational message only; no user action is required.
2011-10-08 11:14:42.43 spid16s     deadlock-list
2011-10-08 11:14:42.43 spid16s      deadlock victim=process3313558
2011-10-08 11:14:42.43 spid16s       process-list
2011-10-08 11:14:42.43 spid16s        process id=process3313558 taskpriority=0 logused=132 waitresource=KEY: 8:72057594047889408 (03000d8f0ecc) waittime=3935 ownerId=623111 transactionname=user_transaction lasttranstarted=2011-10-08T11:13:38.497 XDES=0x574bb30 lockMode=RangeI-N schedulerid=4 kpid=8728 status=suspended spid=52 sbid=0 ecid=0 priority=0 trancount=2 lastbatchstarted=2011-10-08T11:13:38.497 lastbatchcompleted=2011-10-08T11:13:38.497 clientapp=Microsoft SQL Server Management Studio - Query hostname=TUSNC012LKVT006 hostpid=4412 loginname=US1\v983294 isolationlevel=serializable (4) xactid=623111 currentdb=8 lockTimeout=4294967295 clientoption1=671090784 clientoption2=390200
2011-10-08 11:14:42.43 spid16s         executionStack
2011-10-08 11:14:42.43 spid16s          frame procname=adhoc line=4 stmtstart=182 stmtend=296 sqlhandle=0x02000000d2ef471c04bdc8903318b80f6975779f09b41ba8
2011-10-08 11:14:42.43 spid16s     insert into mytable values (2,2, replicate('a','4000'))     
2011-10-08 11:14:42.43 spid16s         inputbuf
2011-10-08 11:14:42.43 spid16s     if not exists (select id from mytable where val = 2)
2011-10-08 11:14:42.43 spid16s     begin
2011-10-08 11:14:42.43 spid16s       waitfor delay '00:01:00'
2011-10-08 11:14:42.43 spid16s       insert into mytable values (2,2, replicate('a','4000')) 
2011-10-08 11:14:42.43 spid16s     end
2011-10-08 11:14:42.43 spid16s        process id=process69eaa8 taskpriority=0 logused=132 waitresource=KEY: 8:72057594047889408 (ffffffffffff) waittime=9293 ownerId=623056 transactionname=user_transaction lasttranstarted=2011-10-08T11:13:32.760 XDES=0xff48c10 lockMode=RangeI-N schedulerid=2 kpid=11340 status=suspended spid=53 sbid=0 ecid=0 priority=0 trancount=2 lastbatchstarted=2011-10-08T11:13:32.760 lastbatchcompleted=2011-10-08T11:13:32.760 clientapp=Microsoft SQL Server Management Studio - Query hostname=TUSNC012LKVT006 hostpid=4412 loginname=US1\v983294 isolationlevel=serializable (4) xactid=623056 currentdb=8 lockTimeout=4294967295 clientoption1=671090784 clientoption2=390200
2011-10-08 11:14:42.43 spid16s         executionStack
2011-10-08 11:14:42.43 spid16s          frame procname=adhoc line=4 stmtstart=182 stmtend=296 sqlhandle=0x02000000eec4b91030fbd7eaeeef1609e5a77d124395f09a
2011-10-08 11:14:42.43 spid16s     insert into mytable values (4,4, replicate('a','4000'))     
2011-10-08 11:14:42.43 spid16s         inputbuf
2011-10-08 11:14:42.43 spid16s     if not exists (select id from mytable where val = 4)
2011-10-08 11:14:42.43 spid16s     begin
2011-10-08 11:14:42.43 spid16s       waitfor delay '00:01:00'
2011-10-08 11:14:42.43 spid16s       insert into mytable values (4,4, replicate('a','4000')) 
2011-10-08 11:14:42.43 spid16s     end
2011-10-08 11:14:42.43 spid16s       resource-list
2011-10-08 11:14:42.43 spid16s        keylock hobtid=72057594047889408 dbid=8 objectname=testdata.dbo.mytable indexname=index01 id=lock55da680 mode=RangeS-S associatedObjectId=72057594047889408
2011-10-08 11:14:42.43 spid16s         owner-list
2011-10-08 11:14:42.43 spid16s          owner id=process69eaa8 mode=RangeS-S
2011-10-08 11:14:42.43 spid16s         waiter-list
2011-10-08 11:14:42.43 spid16s          waiter id=process3313558 mode=RangeI-N requestType=convert
2011-10-08 11:14:42.43 spid16s        keylock hobtid=72057594047889408 dbid=8 objectname=testdata.dbo.mytable indexname=index01 id=lock627aa80 mode=RangeS-S associatedObjectId=72057594047889408
2011-10-08 11:14:42.43 spid16s         owner-list
2011-10-08 11:14:42.43 spid16s          owner id=process3313558 mode=RangeS-S
2011-10-08 11:14:42.43 spid16s         waiter-list
2011-10-08 11:14:42.43 spid16s          waiter id=process69eaa8 mode=RangeI-N requestType=convert


--------------------- end of error log  ------------------

The solution to this deadlock situation could be (1) using repeated read isolation level  and/or (2) create an index on the 'val' column. Bottom line, we have to fully understand the requirement to code properly: why we need to insert into a table then using trigger to insert into another table? But this is out of my reach.  Here I am just satisfied with being familiar with SQL Server lock types and DBCC trace command a little bit.

The deadlock shown in this test case belong to a type of deadlock named conversion deadlock. Looking closely at the "resource-list" section of the error log. We can see that both sessions hold the same resource in shared mode (RangeS-S) at the begining. This is no problem. But both sessions then request to convert the lock type to RangeI-N, this reqires the other session give up the RangeS-S lock first. Thus a deadlock happens.