High Waiting on "SQL*Net message from dblink" Of DML Statement Caused By Row Lock Contention On Remote DB
(Doc ID 2668585.1)
Last updated on JULY 20, 2024
Applies to:
Oracle Database - Enterprise Edition - Version 12.1.0.2 and laterInformation in this document applies to any platform.
Symptoms
- In customer environment, update statement via DBLINK waits on "SQL*Net message from dblink" for longer time intermittently, that supposed to complete within seconds.
SAMPLE_TIME SESSION_ID SESSION_SERIAL# SESSION_TYPE SQL_ID SQL_OPNAME EVENT BLOCKING_SESSION BLOCKING_SESSION_SERIAL#
2020/04/13 09:52:00.968 2190 36328 FOREGROUND 98vqnypnnmpak UPDATE
2020/04/13 09:52:28.014 2190 36328 FOREGROUND 98vqnypnnmpak UPDATE SQL*Net message from dblink
......
2020/04/13 09:56:26.818 2190 36328 FOREGROUND 98vqnypnnmpak UPDATE SQL*Net message from dblink - In remote environment of DBLINK, high waiting on "enq: TX - row lock contention" can be observed on the target table of this update statement.
SAMPLE_TIME SESSION_ID SESSION_SERIAL# SESSION_TYPE SQL_ID SQL_OPNAME EVENT BLOCKING_SESSION BLOCKING_SESSION_SERIAL# CURRENT_OBJ#
2020/04/13 09:52:07.206 2474 46688 FOREGROUND 8k68t3kkqf3mg UPDATE enq: TX - row lock contention 2571 9114 59701
2020/04/13 09:52:06.206 2474 46688 FOREGROUND 8k68t3kkqf3mg UPDATE enq: TX - row lock contention 2571 9114 59701
2020/04/13 09:52:05.206 2474 46688 FOREGROUND 8k68t3kkqf3mg UPDATE enq: TX - row lock contention 2571 9114 59701
... ... - This problem can be reproduced by simple test case as following:
Test preparation
=============================
Remote Environment:
grant dba to <USER_NAME> identified by <PASSWORD>;
SQL> conn <USER_NAME>/<PASSWORD>
SQL> create table <TABLE_NAME>(col1 number, col2 varchar2(30), constraint pk_<TABLE_NAME> primary key(col1));
SQL> insert into <TABLE_NAME> select level, 'A'||level from dual connect by level <=100;
SQL> commit;
Local Environment:
sqlplus / as sysdba
create public database link <DBLINK_NAME> connect to <USER_NAME> identified by <PASSWORD> using '<CONNECTION_STRING>';
Test scenario
=============================
Remote Environment:
conn <USER_NAME>/<PASSWORD>
select * from <TABLE_NAME> for update;
Local Environment:
alter session set tracefile_identifier='10046';
alter session set max_dump_file_size = UNLIMITED;
alter session set timed_statistics=true;
alter session set events '10046 trace name context forever, level 12';
update <TABLE_NAME>@<DBLINK_NAME> set col2='ttt' where col1=1;
alter session set events '10046 trace name context off';
select value from v$diag_info where name like 'Default Trace File%';
Remote Environment:
rollback;
Test log
=============================
Remote Environment:
SQL> select * from <TABLE_NAME> for update;
COL1 COL2
---------- ------------------------------
1 A1
2 A2
... ...
100 rows selected.
Local Environment:
SQL> alter session set tracefile_identifier='10046';
alter session set max_dump_file_size = UNLIMITED;
alter session set timed_statistics=true;
alter session set events '10046 trace name context forever, level 12';
Session altered.
SQL>
Session altered.
SQL>
Session altered.
SQL>
Session altered.
SQL>
SQL> update <TABLE_NAME>@<DBLINK_NAME> set col2='ttt' where col1=1; <<<<<<<<<Hang
Remote Environment:
SQL> rollback;
Rollback complete.
Local Environment:
1 row updated.
SQL> alter session set events '10046 trace name context off';
select value from v$diag_info where name like 'Default Trace File%';
Session altered.
SQL>
VALUE
--------------------------------------------------------------------------------
/refresh/home/app/12.1.0.2/oracle/diag/rdbms/orcl12102/orcl12102/trace/orcl12102
_ora_27527_10046.trc
The abstract of trace file:
----------------------------------------------------------------------------------------------
SQL ID: dtyntypc3hbfn Plan Hash: 0
update <TABLE_NAME>@<DBLINK_NAME> set col2='ttt'
where
col1=1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.02 0 2 0 0
Execute 1 0.00 21.09 0 0 0 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 21.12 0 2 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to dblink 3 0.00 0.00
SQL*Net message from dblink 3 21.09 21.12 <<<<<<<<<<<<<<<<<
Disk file operations I/O 1 0.00 0.00
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 8.59 8.59
********************************************************************************
----------------------------------------------------------------------------------------------
Changes
Cause
To view full details, sign in with your My Oracle Support account. |
|
Don't have a My Oracle Support account? Click to get started! |
In this Document
Symptoms |
Changes |
Cause |
Solution |