【问题描述】

客户遇到如下问题：

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.

【参考文档】

Bug 27223075 - Wait for 'PX Deq: Join Ack' when no active QC but PPA* slaves show as busy (Doc ID 27223075.8)