Issue Finding cause of deadlock error from oracle trace file

Question

I'm testing an application using several clients. At some point i get a Deadlock in the database. I get the following traces:

Caused by: com.indra.davinci.common.dataaccess.DataAccessException: SQL:DELETE FROM EMPLOYEE WHERE DEPT_ID IN (SELECT ID FROM DPTO WHERE COMPANY_ID = ?), arguments:[409386]

and

Caused by: java.sql.SQLException: ORA-00060: deadlock detected while waiting for resource

The table EMPLOYEE has two child tables (MANAGER and DEVELOPER) both with foreign keys to EMPLOYEE. I have created indexes for the foreign keys. The Delete on cascade is NOT set. On the other hand, the code of the application performs the following: 1. Deletes the rows in child table MANAGER that belongs to a concrete EMPLOYEE. 2. Deletes the rows in child table DEVELOPER that belongs to a concrete EMPLOYEE. 3. Deletes the row in the EMPLOYEE table. 4. Deletes the row in DPTO table (EMPLOYEE is child of DPTO, there is a foreign key and an index created).

I have set traces in the application in order to get the performance order of the requests, and i see the following:

06/09/2017 08:43:13.539 INIT DELETE MANAGER client: 409383

06/09/2017 08:43:13.539 INIT DELETE MANAGER client: 409386

06/09/2017 08:43:13.555 END DELETE MANAGER client: 409386

06/09/2017 08:43:13.555 INIT DELETE DEVELOPER client: 409386

06/09/2017 08:43:13.555 END DELETE MANAGER client: 409383

06/09/2017 08:43:13.555 INIT DELETE DEVELOPER client: 409383

06/09/2017 08:43:13.555 END DELETE DEVELOPER client: 409386

06/09/2017 08:43:13.555 INIT DELETE EMPLOYEE client: 409386

06/09/2017 08:43:13.555 END DELETE DEVELOPER client: 409383

06/09/2017 08:43:13.555 INIT DELETE EMPLOYEE client: 409383

06/09/2017 08:43:13.555 INIT DELETE MANAGER client: 409389

06/09/2017 08:43:13.570 INIT DELETE MANAGER client: 409407

06/09/2017 08:43:13.570 END DELETE MANAGER client: 409389

06/09/2017 08:43:13.570 INIT DELETE DEVELOPER client: 409389

06/09/2017 08:43:13.570 END DELETE DEVELOPER client: 409389

06/09/2017 08:43:13.570 INIT DELETE EMPLOYEE client: 409389

06/09/2017 08:43:13.570 END DELETE MANAGER client: 409407

06/09/2017 08:43:13.570 INIT DELETE DEVELOPER client: 409407

06/09/2017 08:43:13.570 END DELETE DEVELOPER client: 409407

06/09/2017 08:43:13.570 INIT DELETE EMPLOYEE client: 409407

It seems that at instant 08:43:13.555 two clients are trying to delete from EMPLOYEE table.

I get the following in the trace file from Oracle:

Trace file C:\ORACLEXE\APP\ORACLE\diag\rdbms\xe\xe\trace\xe_ora_10068.trc
Oracle Database 11g Express Edition Release 11.2.0.2.0 - Production
Windows NT Version V6.1 Service Pack 1 
CPU                 : 4 - type 586, 2 Physical Cores
Process Affinity    : 0x0x00000000
Memory (Avail/Total): Ph:2347M/16247M, Ph+PgF:15271M/32493M, VA:2685M/4095M 
Instance name: xe
Redo thread mounted by this instance: 1
Oracle process number: 36
Windows thread id: 10068, image: ORACLE.EXE (SHAD)


*** 2017-09-06 08:43:16.613
*** SESSION ID:(11.369) 2017-09-06 08:43:16.613
*** CLIENT ID:() 2017-09-06 08:43:16.613
*** SERVICE NAME:(XE) 2017-09-06 08:43:16.613
*** MODULE NAME:(JDBC Thin Client) 2017-09-06 08:43:16.613
*** ACTION NAME:() 2017-09-06 08:43:16.613



*** 2017-09-06 08:43:16.613
DEADLOCK DETECTED ( ORA-00060 )

[Transaction Deadlock]

The following deadlock is not an ORACLE error. It is a
deadlock due to user error in the design of an application
or from issuing incorrect ad-hoc SQL. The following
information may aid in determining the deadlock:

Deadlock graph:
                       ---------Blocker(s)--------  ---------Waiter(s)---------
Resource Name          process session holds waits  process session holds waits
TM-0008747d-00000000        36      11    SX   SSX       32      10    SX   SSX
TM-0008747d-00000000        32      10    SX   SSX       36      11    SX   SSX

session 11: DID 0001-0024-00000114  session 10: DID 0001-0020-0000001C 
session 10: DID 0001-0020-0000001C  session 11: DID 0001-0024-00000114 

Rows waited on:
  Session 11: no row
  Session 10: no row

----- Information for the OTHER waiting sessions -----
Session 10:
  sid: 10 ser: 27 audsid: 14562964 user: 184/USRPLNADIF
    flags: (0x41) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
    flags2: (0x40009) -/-
  pid: 32 O/S info: user: SYSTEM, term: MARRIETAW7, ospid: 13724
    image: ORACLE.EXE (SHAD)
  client details:
    O/S info: user: marrieta, term: unknown, ospid: 1234
    machine: marrietaw7 program: JDBC Thin Client
    application name: JDBC Thin Client, hash value=2546894660
  current SQL:
  DELETE FROM EMPLOYEE WHERE DEPT_ID IN (SELECT ID FROM DPTO WHERE COMPANY_ID = :1)

----- End of information for the OTHER waiting sessions -----

Information for THIS session:

----- Current SQL Statement for this session (sql_id=6v66dbfh41hbx) -----
DELETE FROM EMPLOYEE WHERE DEPT_ID IN (SELECT ID FROM DPTO WHERE COMPANY_ID = :1)

Any ideas of what could be happening?

Thanks.

Answer 1

Well, i have check the deadlock graph in the trace file, in concrete this part:

Deadlock graph:
                       ---------Blocker(s)--------  ---------Waiter(s)---------
Resource Name          process session holds waits  process session holds waits
TM-0008747d-00000000        36      11    SX   SSX       32      10    SX   SSX
TM-0008747d-00000000        32      10    SX   SSX       36      11    SX   SSX

I converted the hexadecimal 0008747d to decimal and execute the following:

SELECT * FROM dba_objects WHERE object_id= 554109;

I got the table that is blocking the database. This table is not used by the application but is created in the database (maybe in an old version of the app it was used) and i found out that this table is child of EMPLOYEE and does not have an index for the FK. I'm gonna try to fix this and i will comment.