【问题描述】
客户遇到如下问题:
jtsbdbp1[/oracle/app/oracle/diag/rdbms/jtsbp/jtsbp1/trace]#more jtsbp1_ppa7_6369.trc
Trace file /oracle/app/oracle/diag/rdbms/jtsbp/jtsbp1/trace/jtsbp1_ppa7_6369.trc
Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production
Build label: RDBMS_12.2.0.1.0_HPUX.IA64_170125.170321
ORACLE_HOME: /oracle/app/oracle/product/12.2.0/db_1
System name: HP-UX
Node name: jtsbdbp1
Release: B.11.31
Version: U
Machine: ia64
Instance name: jtsbp1
Redo thread mounted by this instance: 1
Oracle process number: 87
Unix process pid: 6369, image: oracle@jtsbdbp1 (PPA7)
*** 2021-02-22T10:43:44.136928+08:00
*** SESSION ID:(2014.24989) 2021-02-22T10:43:44.136990+08:00
*** CLIENT ID:() 2021-02-22T10:43:44.137006+08:00
*** SERVICE NAME:() 2021-02-22T10:43:44.137022+08:00
*** MODULE NAME:() 2021-02-22T10:43:44.137038+08:00
*** ACTION NAME:() 2021-02-22T10:43:44.137053+08:00
*** CLIENT DRIVER:() 2021-02-22T10:43:44.137068+08:00
IPCLW:[0.0]{E}[WAIT]:PROTO: [1613961824135848]PCNH 9ffffffffd0cfa88 deferred delete timer expired pending MSN 249795017 -> 249795018
*** 2021-02-22T10:44:01.609740+08:00
IPCLW:[0.1]{E}[WAIT]:PROTO: [1613961841609701]PCNH 9ffffffffd0cf4f8 deferred delete timer expired pending MSN 1690648772 -> 1690648773
*** 2021-02-22T10:48:43.784225+08:00
IPCLW:[0.2]{E}[WAIT]:PROTO: [1613962123784185]PCNH 9ffffffffd0cef68 deferred delete timer expired pending MSN 141289430 -> 141289431
*** 2021-02-22T10:50:43.054041+08:00
IPCLW:[0.3]{E}[WAIT]:PROTO: [1613962243054003]PCNH 9ffffffffd0cf4f8 deferred delete timer expired pending MSN 2047756617 -> 2047756618
IPCLW:[0.4]{E}[WAIT]:PROTO: [1613962425539864]PCNH 9ffffffffd0cfa88 deferred delete timer expired pending MSN 1034686901 -> 1034686902
*** 2021-02-22T10:54:03.106364+08:00
IPCLW:[0.5]{E}[WAIT]:PROTO: [1613962443106321]PCNH 9ffffffffd0cef68 deferred delete timer expired pending MSN 1555121684 -> 1555121685
*** 2021-02-22T10:55:41.220317+08:00
IPCLW:[0.6]{E}[WAIT]:PROTO: [1613962541220279]PCNH 9ffffffffd0ce9d8 deferred delete timer expired pending MSN 844947901 -> 844947902
*** 2021-02-22T10:57:47.830752+08:00
IPCLW:[0.7]{E}[WAIT]:PROTO: [1613962667830697]PCNH 9ffffffffd0cf4f8 deferred delete timer expired pending MSN 412924904 -> 412924905
*** 2021-02-22T11:00:22.273489+08:00
IPCLW:[0.8]{E}[WAIT]:PROTO: [1613962822273446]PCNH 9ffffffffd0cef68 deferred delete timer expired pending MSN 426392795 -> 426392796
*** 2021-02-22T11:00:40.825660+08:00
IPCLW:[0.9]{E}[WAIT]:PROTO: [1613962840825621]PCNH 9ffffffffd0cfa88 deferred delete timer expired pending MSN 1883918113 -> 1883918114
*** 2021-02-22T11:03:47.279211+08:00
IPCLW:[0.10]{E}[WAIT]:PROTO: [1613963027279164]PCNH 9ffffffffd0cf4f8 deferred delete timer expired pending MSN 1056827817 -> 1056827818
*** 2021-02-22T11:04:04.734778+08:00
IPCLW:[0.11]{E}[WAIT]:PROTO: [1613963044734739]PCNH 9ffffffffd0ce9d8 deferred delete timer expired pending MSN 843228062 -> 843228063
*** 2021-02-22T11:05:46.396886+08:00
IPCLW:[0.12]{E}[WAIT]:PROTO: [1613963146396842]PCNH 9ffffffffd0cef68 deferred delete timer expired pending MSN 1750313126 -> 1750313127
IPCLW:[0.13]{E}[WAIT]:PROTO: [1613963272447638]PCNH 9ffffffffd0cfa88 deferred delete timer expired pending MSN 957358121 -> 957358122
*** 2021-02-22T11:08:15.199136+08:00
IPCLW:[0.14]{E}[WAIT]:PROTO: [1613963295199095]PCNH 9ffffffffd0ce448 deferred delete timer expired pending MSN 1106114103 -> 1106114104
*** 2021-02-22T11:08:32.199628+08:00
IPCLW:[0.15]{E}[WAIT]:PROTO: [1613963312199586]PCNH 9ffffffffd0cdeb8 deferred delete timer expired pending MSN 679405679 -> 679405680
*** 2021-02-22T11:10:42.829980+08:00
IPCLW:[0.16]{E}[WAIT]:PROTO: [1613963442829934]PCNH 9ffffffffd0ce9d8 deferred delete timer expired pending MSN 559955168 -> 559955169
*** 2021-02-22T11:13:48.807152+08:00
IPCLW:[0.17]{E}[WAIT]:PROTO: [1613963628807103]PCNH 9ffffffffd0ce448 deferred delete timer expired pending MSN 835762534 -> 835762535
*** 2021-02-22T11:14:06.282130+08:00
IPCLW:[0.18]{E}[WAIT]:PROTO: [1613963646282080]PCNH 9ffffffffd0cdeb8 deferred delete timer expired pending MSN 1094735753 -> 1094735754
*** 2021-02-22T11:15:42.326385+08:00
IPCLW:[0.19]{E}[WAIT]:PROTO: [1613963742326333]PCNH 9ffffffffd0cfa88 deferred delete timer expired pending MSN 104439035 -> 104439036
*** 2021-02-22T11:17:57.281515+08:00
IPCLW:[0.20]{E}[WAIT]:PROTO: [1613963877281472]PCNH 9ffffffffd0ce9d8 deferred delete timer expired pending MSN 404152961 -> 404152962
*** 2021-02-22T11:19:24.335080+08:00
IPCLW:[0.21]{E}[WAIT]:PROTO: [1613963964335039]PCNH 9ffffffffd0cdeb8 deferred delete timer expired pending MSN 1834154017 -> 1834154018
*** 2021-02-22T11:20:10.407926+08:00
IPCLW:[0.22]{E}[WAIT]:PROTO: [1613964010407852]PCNH 9ffffffffd0ce448 deferred delete timer expired pending MSN 965645358 -> 965645359
*** 2021-02-22T11:21:27.858334+08:00
IPCLW:[0.23]{E}[WAIT]:PROTO: [1613964087858285]PCNH 9ffffffffd0cfa88 deferred delete timer expired pending MSN 695429471 -> 695429472
jtsbdbp1[/oracle/app/oracle/diag/rdbms/jtsbp/jtsbp1/trace]#
【问题解决】
此问题很可能是BUG,是由于并行进程导致的。
Rediscovery: A PPA* slave that is busy is thought to be available by a QC and is asked to join, but the slave cannot report back to the QC, so it hangs and has to be killed. You may run the following queries and see no rows returned from the first one, and PPA* slaves returned from the second one: 1. No Query slaves running. select decode(px.qcinst_id,NULL,username, ' - '||lower(substr(s.program,length(s.program)-4,4) ) ) "Username", decode(px.qcinst_id,NULL, 'QC', '(Slave)') "QC/Slave" , to_char( px.server_set) "Slave Set", to_char(s.sid) "SID", decode(px.qcinst_id, NULL ,to_char(s.sid) ,px.qcsid) "QC SID", px.req_degree "Requested DOP", px.degree "Actual DOP" from v$px_session px, v$session s where px.sid=s.sid (+) and px.serial#=s.serial# order by 5 , 1 desc / no rows selected ... 2. But PPA4/PPA5/PPA6/PPA7 are busy. SQL> select SLAVE_NAME from V$PQ_SLAVE where STATUS='BUSY'; SLAV ---- PPA4 PPA5 PPA6 PPA7 Additional Info: Any parallel slave process (p00*) can be affected by this bug and is not constrained to PPA* slaves.
【参考文档】