Shulou(Shulou.com)05/31 Report--

This article mainly introduces the database how to use systemstate dump trace files to find dg terminated reasons, has a certain reference value, interested friends can refer to, I hope you can learn a lot after reading this article, the following let Xiaobian take you to understand.

An alarm was received that a dataguard was down. The software version is 11.2.0.4. Log in to view the alert file first.

Fri Jan 25 11:00:39 2019

System State dumped to trace file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_ora_42298.trc

Fri Jan 25 11:00:54 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_ora_42298.trc:

Fri Jan 25 11:00:58 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_pmon_56104.trc:

ORA-03170: deadlocked on readable physical standby (undo segment 65535)

Fri Jan 25 11:01:19 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_pmon_56104.trc:

ORA-03170: deadlocked on readable physical standby (undo segment 65535)

Fri Jan 25 11:01:39 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_pmon_56104.trc:

ORA-03170: deadlocked on readable physical standby (undo segment 65535)

Fri Jan 25 11:01:59 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_pmon_56104.trc:

ORA-03170: deadlocked on readable physical standby (undo segment 65535)

Fri Jan 25 11:02:19 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_pmon_56104.trc:

ORA-03170: deadlocked on readable physical standby (undo segment 65535)

Fri Jan 25 11:02:40 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_pmon_56104.trc:

ORA-03170: deadlocked on readable physical standby (undo segment 65535)

Fri Jan 25 11:03:00 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_pmon_56104.trc:

ORA-03170: deadlocked on readable physical standby (undo segment 65535)

Fri Jan 25 11:03:21 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_pmon_56104.trc:

ORA-03170: deadlocked on readable physical standby (undo segment 65535)

Fri Jan 25 11:03:41 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_pmon_56104.trc:

ORA-03170: deadlocked on readable physical standby (undo segment 65535)

Fri Jan 25 11:04:01 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_pmon_56104.trc:

ORA-03170: deadlocked on readable physical standby (undo segment 65535)

Fri Jan 25 11:04:21 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_pmon_56104.trc:

ORA-03170: deadlocked on readable physical standby (undo segment 65535)

Fri Jan 25 11:04:41 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_pmon_56104.trc:

ORA-03170: deadlocked on readable physical standby (undo segment 65535)

Fri Jan 25 11:05:01 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_pmon_56104.trc:

ORA-03170: deadlocked on readable physical standby (undo segment 65535)

Fri Jan 25 11:05:21 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_pmon_56104.trc:

ORA-03170: deadlocked on readable physical standby (undo segment 65535)

Fri Jan 25 11:05:27 2019

RFS [3]: Selected log 9 for thread 1 sequence 85314 dbid-1036715693 branch 899829907

Fri Jan 25 11:05:27 2019

Media Recovery Waiting for thread 1 sequence 85314 (in transit)

Recovery of Online Redo Log: Thread 1 Group 9 Seq 85314 Reading mem 0

Mem# 0: / san/data/oradata/EIN1/standby_redo03.log

Fri Jan 25 11:05:27 2019

Archived Log entry 165577 added for thread 1 sequence 85313 ID 0xc2352453 dest 1:

Fri Jan 25 11:05:41 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_pmon_56104.trc:

ORA-03170: deadlocked on readable physical standby (undo segment 65535)

Fri Jan 25 11:06:01 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_pmon_56104.trc:

ORA-03170: deadlocked on readable physical standby (undo segment 65535)

Fri Jan 25 11:06:21 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_pmon_56104.trc:

ORA-03170: deadlocked on readable physical standby (undo segment 65535)

Fri Jan 25 11:06:41 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_pmon_56104.trc:

ORA-03170: deadlocked on readable physical standby (undo segment 65535)

Fri Jan 25 11:06:45 2019

Errors in file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_lgwr_56177.trc:

ORA-04020: deadlock detected while trying to lock object SYS.ERAC

LGWR (ospid: 56177): terminating the instance due to error 4020

Fri Jan 25 11:06:46 2019

System state dump requested by (instance=1, osid=56177 (LGWR)), summary= [abnormal instance termination].

System State dumped to trace file / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_diag_56159_20190125110646.trc

You can see a large number of persistent ORA-03170 deadlock alarms, and the instance is terminated at 11:06: 46. A trace file is generated at the beginning of the posted alert log. First analyze this file.

Vi edit the / u01/app/oracle/diag/rdbms/eracpdg01/ERAC/trace/ERAC_ora_42298.trc file, search for the keyword final, and navigate to the following paragraph:

SO: 0xa1cccae30, type: 4, owner: 0xa0c7c8da8, flag: INIT/-/-/0x00 if: 0x3 c: 0x3

Proc=0xa0c7c8da8, name=session, file=ksu.h LINE:12729, pg=0

(session) sid: 2228 ser: 9 trans: (nil), creator: 0xa0c7c8da8

Flags: (0x45) USR/- flags_idl: (0x1) BSY/-

Flags2: (0x40009)-/-/ INC

DID:, short-term DID:

Txn branch: (nil)

Edition#: 100 oct: 3, prv: 0, sql: 0xa33cf5e08, psql: 0xa3e7cdec0, user: 627/CONVERT_R

Ksuxds FALSE at location: 0

Service name: SYS$USERS

Client details:

S info: user: EM-H6VQXD2 $, term: unknown, ospid: 1234

Machine: EM-H6VQXD2 program: JDBC Thin Client

Application name: JDBC Thin Client, hash value=2546894660

Current Wait Stack:

0: waiting for 'library cache lock'

Handle address=0xa3ff9eb18, lock address=0x50de690a0, 100*mode+namespace=0x1004a0002

Wait_id=945878 seq_num=28394 snap_id=1

Wait times: snap=2 min 53 sec, exc=2 min 53 sec, total=2 min 53 sec

Wait times: max=15 min 0 sec, heur=2 min 53 sec

Wait counts: calls=60 os=60

In_wait=1 iflags=0x15a2

There is at least one session blocking this session.

Dumping 1 direct blocker (s):

Inst: 1, sid: 970, ser: 1

Dumping final blocker:

Inst: 1, sid: 2059, ser: 26985

Wait State:

Fixed_waits=0 flags=0x22 boundary= (nil) /-1

Session Wait History:

Elapsed time of 0.000134 sec since current wait

0: waited for 'SQL*Net message from client'

Driver id=0x54435000, # bytes=0x1, = 0x0

Wait_id=945877 seq_num=28393 snap_id=1

Wait times: snap=3.470941 sec, exc=3.470941 sec, total=3.470941 sec

Wait times: max=infinite

Wait counts: calls=0 os=0

Occurred after 0.000001 sec of elapsed time

1: waited for 'SQL*Net message to client'

Driver id=0x54435000, # bytes=0x1, = 0x0

Wait_id=945876 seq_num=28392 snap_id=1

Wait times: snap=0.000001 sec, exc=0.000001 sec, total=0.000001 sec

Wait times: max=infinite

Wait counts: calls=0 os=0

Occurred after 0.000048 sec of elapsed time

You can see that the source of the blocker is sid: 2059, ser: 26985 this session.

Here SO is 0xa1cccae30, type: 4 indicates session information, and owner: 0xa0c7c8da8 is the parent node of this SO (0xa1cccae30).

Search the PROCESS process where this location is located and find that it is the LGWR process

PROCESS 17: LGWR

Then search directly for sid: 2059 ser: 26985

SO: 0xa18befcd0, type: 4, owner: 0xa18786ed8, flag: INIT/-/-/0x00 if: 0x3 c: 0x3

Proc=0xa18786ed8, name=session, file=ksu.h LINE:12729, pg=0

(session) sid: 2059 ser: 26985 trans: 0xa1b361290, creator: 0xa18786ed8

Flags: (0x41) USR/- flags_idl: (0x1) BSY/-

Flags2: (0x40009)-/-/ INC

DID:, short-term DID:

Txn branch: 0xa0f20f998

Edition#: 100 oct: 3, prv: 0, sql: 0xa345bb8d0, psql: 0xa2fe3c0a8, user: 510/READER

Ksuxds FALSE at location: 0

Service name: SYS$USERS

Client details:

O/S info: user: Administrator, term: ADMIN-PC, ospid: 8960:8832

Machine: WORKGROUP\ ADMIN-PC program: plsqldev.exe

Application name: PL/SQL Developer, hash value=1190136663

Action name: SQL window-ISIN Hong Kong net worth. SQL, hash value=506963986

Current Wait Stack:

0: waiting for 'SQL*Net message from dblink'

Driver id=0x28444553, # bytes=0x1, = 0x0

Wait_id=474 seq_num=475 snap_id=1

Wait times: snap=4 min 45 sec, exc=4 min 45 sec, total=4 min 45 sec

Wait times: max=infinite, heur=4 min 45 sec

Wait counts: calls=0 os=0

In_wait=1 iflags=0x5a0

There are 28 sessions blocked by this session.

You can see that it is caused by a piece of sql text initiated by reader users from the PL/SQL developer of a Windows. And this sql uses db_link. It has lasted 4 minutes and 45 seconds, nearly 5 minutes. The session blocked 28 sessions.

The complete blocking situation may not have been achieved so far, but it has been concluded that the LGWR process is blocked by a PL/SQL developer session, and the instance is terminated by LGWR after the sql text has been executed for nearly five minutes.

Why is it five minutes here? This is because of other failures that have occurred before, when an implicit parameter _ adg_parselock_timeout was modified.

SQL > col name for A30

SQL > col value for A20

SQL > col description for A70

SQL > set line 150

SQL > select a.ksppinm name,b.ksppstvl value,a.ksppdesc description

2 from x$ksppi a dint Xeroksppcv b

3 where a.inst_id = USERENV ('Instance')

4 and b.inst_id = USERENV ('Instance')

5 and a.indx = b.indx

6 and upper (a.ksppinm) LIKE upper ('% adg_parselock_timeout%')

7 order by name

NAME VALUE DESCRIPTION

_ adg_parselock_timeout 30000 timeout for parselock get on ADG in centiseconds

_ adg_parselock_timeout_sleep 100 sleep duration after a parselock timeout on ADG in milliseconds

SQL > col name for A30

SQL > col value for A10

SQL > select * from

2 (select

3 x.ksppinm name

4 y.ksppstvl value

5 y.ksppstdf isdefault

6 decode (bitand (y.ksppstvf 7), 1 ismod, 4 ismod

7 decode (bitand (y.ksppstvfj2), 2 isadj

8 from

9 sys.x$ksppi x

10 sys.x$ksppcv y

11 where

12 x.inst_id = userenv ('Instance') and

13 y.inst_id = userenv ('Instance') and

14 x.indx = y.indx

15 order by

16 translate (x.ksppinm,'_',') T where T.name like'% adg_parselock_timeout%'

NAME VALUE ISDEFAULT ISMOD ISADJ

_ adg_parselock_timeout 30000 FALSE FALSE FALSE

_ adg_parselock_timeout_sleep 100 TRUE FALSE FALSE

_ adg_parselock_timeout this value is set to 30000 centiseconds, which is about 300 seconds, or five minutes.

Confirm as BUG after searching MOS

Bug 18515268 ORA-4020 in ADG Standby Database causing instance crash by LGWR

Solution

Apply interim patch 18515268, if available for your platform and Oracle version.

Fixed releases: 11.2.0.4.BP20 12.1.0.2 12.2.0.1

Thank you for reading this article carefully. I hope the article "how to use systemstate dump trace files to find the reasons for dg terminated in the database" shared by the editor will be helpful to everyone. At the same time, I also hope that you will support us and pay attention to the industry information channel. More related knowledge is waiting for you to learn!

Welcome to subscribe "Shulou Technology Information " to get latest news, interesting things and hot topics in the IT industry, and controls the hottest and latest Internet news, technology news and IT industry trends.