E-IB: Application Server PUBSUB dispatcher fails to boot (Doc ID 1343620.1)

Last updated on AUGUST 28, 2023

Applies to:

Symptoms

Environment:
-------------------
PeopleTools 8.51.06
Oracle 11.2.0.1.0

Issue:
-------
The issue is that application server domain PUBSUB dispatchers PSBRKDSP/PSPUBDSP fails to start.   And when queried from backend, see a lock

BLOCKING_STATUS
--------------------------------------------------------------------------------
SYSADM@vmpodlqta004 ( SID=10 )  is blocking SYSADM@vmpodlqta004 ( SID=7 )

Error:
--------

Booting server processes ...

exec PSWATCHSRV -o ./LOGS/stdout -e ./LOGS/stderr -A -- -ID 244509 -D DLQT2J01 -S PSWATCHSRV :
      process id=12079 ... Started.
exec PSAPPSRV -o ./LOGS/stdout -e ./LOGS/stderr -s@psappsrv.lst -- -D DLQT2J01 -S PSAPPSRV :
      process id=12080 ... Started.
exec PSAPPSRV -o ./LOGS/stdout -e ./LOGS/stderr -s@psappsrv.lst -- -D DLQT2J01 -S PSAPPSRV :
      process id=12090 ... Started.
exec PSSAMSRV -o ./LOGS/stdout -e ./LOGS/stderr -A -- -D DLQT2J01 -S PSSAMSRV :
      process id=12097 ... Started.
exec PSBRKHND -o ./LOGS/stdout -e ./LOGS/stderr -s PSBRKHND_dflt:BrkProcess -- -D DLQT2J01 -S PSBRKHND_dflt :
      process id=12102 ... Started.
exec PSBRKHND -o ./LOGS/stdout -e ./LOGS/stderr -s PSBRKHND_dflt:BrkProcess -- -D DLQT2J01 -S PSBRKHND_dflt :
      process id=12110 ... Started.
exec PSBRKDSP -o ./LOGS/stdout -e ./LOGS/stderr -s PSBRKDSP_dflt:Dispatch -- -D DLQT2J01 -S PSBRKDSP_dflt :
      process id=12115 ... Started.
exec PSPUBHND -o ./LOGS/stdout -e ./LOGS/stderr -s PSPUBHND_dflt:PubConProcess -- -D DLQT2J01 -S PSPUBHND_dflt :
      process id=12147 ... Started.
exec PSPUBHND -o ./LOGS/stdout -e ./LOGS/stderr -s PSPUBHND_dflt:PubConProcess -- -D DLQT2J01 -S PSPUBHND_dflt :
      process id=12153 ... Started.
exec PSPUBDSP -o ./LOGS/stdout -e ./LOGS/stderr -s PSPUBDSP_dflt:Dispatch -- -D DLQT2J01 -S PSPUBDSP_dflt :
      CMDTUX_CAT:1863: INFO: Process ID=12159 Assume failed (timeout).

tmboot: CMDTUX_CAT:827: ERROR: Fatal error encountered; initiating user error handler

exec tmshutdown -qy

The TUXLOG.072111  file from DLQT2J.zip (328.76 KB) (21-Jul-2011 04:05:06 AM) shows the following errors:

000002.vmpodlqta004!BBL.12128.2544839776.0: 07-21-2011: client high water (15), total client (4)
000002.vmpodlqta004!BBL.12128.2544839776.0: 07-21-2011: Tuxedo Version 10.3.0.0, 64-bit, Patch Level 031
000002.vmpodlqta004!BBL.12128.2544839776.0:  
013817.vmpodlqta004!JSL.12222.2062797936.0: JOLT_CAT:1506: "INFO: Terminating Jolt administration services in preparation for shutdown"
013817.vmpodlqta004!JSL.12222.2062797936.0: JOLT_CAT:1196: "INFO: Terminating handlers in preparation for shutdown"
013817.vmpodlqta004!JSL.12222.2062797936.0: JOLT_CAT:1197: "INFO: Exiting system"
013817.vmpodlqta004!JSH.12250.1666487504.-2: JOLT_CAT:1198: "WARN: Forced shutdown of client; user name 'JPOOL_32'; client name '192.57.220.2'"
013817.vmpodlqta004!WSL.12220.2671096032.0: WSNAT_CAT:1196: INFO: Terminating handlers in preparation for shutdown
013817.vmpodlqta004!WSL.12220.2671096032.0: WSNAT_CAT:1197: INFO: Exiting system
013822.vmpodlqta004!BBL.12128.2544839776.0: CMDTUX_CAT:26: INFO: The BBL is exiting system
013843.vmpodlqta004!tmadmin.1308.1971571824.-2: TMADMIN_CAT:1330: INFO: Command: boot -A
013845.vmpodlqta004!tmboot.1309.590878240.-2: 07-21-2011: Tuxedo Version 10.3.0.0, 64-bit
013845.vmpodlqta004!tmboot.1309.590878240.-2: CMDTUX_CAT:1851: INFO: TM_BOOTTIMEOUT is set to 120 seconds
013845.vmpodlqta004!tmboot.1309.590878240.-2: CMDTUX_CAT:1855: INFO: TM_BOOTPRESUMEDFAIL option is selected
013847.vmpodlqta004!BBL.1310.2005003360.0: 07-21-2011: Tuxedo Version 10.3.0.0, 64-bit, Patch Level 031
013847.vmpodlqta004!BBL.1310.2005003360.0: LIBTUX_CAT:262: INFO: Standard main starting
013850.vmpodlqta004!BBL.1310.2005003360.0: CMDTUX_CAT:26: INFO: The BBL is exiting system
013925.vmpodlqta004!tmloadcf.1599.3355841792.-2: 07-21-2011: Tuxedo Version 10.3.0.0, 64-bit
013925.vmpodlqta004!tmloadcf.1599.3355841792.-2: CMDTUX_CAT:879: INFO: A new file system has been created. (size = 1316 512-byte blocks)
013925.vmpodlqta004!tmloadcf.1599.3355841792.-2: CMDTUX_CAT:871: INFO: TUXCONFIG file /dlqt2j/psoft/pt851/hr91/appserv/DLQT2J01/PSTUXCFG has been created
013938.vmpodlqta004!tmadmin.1638.2178604144.-2: TMADMIN_CAT:1330: INFO: Command: boot -A
013940.vmpodlqta004!tmboot.1648.3244144160.-2: 07-21-2011: Tuxedo Version 10.3.0.0, 64-bit
013940.vmpodlqta004!tmboot.1648.3244144160.-2: CMDTUX_CAT:1851: INFO: TM_BOOTTIMEOUT is set to 120 seconds
013940.vmpodlqta004!tmboot.1648.3244144160.-2: CMDTUX_CAT:1855: INFO: TM_BOOTPRESUMEDFAIL option is selected
013942.vmpodlqta004!BBL.1652.2147916896.0: 07-21-2011: Tuxedo Version 10.3.0.0, 64-bit, Patch Level 031
013942.vmpodlqta004!BBL.1652.2147916896.0: LIBTUX_CAT:262: INFO: Standard main starting
013942.vmpodlqta004!BBL.1652.2147916896.0: ERROR: msgrcv err(LIBTUX_CAT:666: ERROR: Message operation failed because the queue was removed): errno=43,qid=755761154,buf=11426968,bytes=4568,type=-1073741824,flag=0
013942.vmpodlqta004!BBL.1652.2147916896.0: ERROR: msgrcv err(LIBTUX_CAT:669: ERROR: Message operation failed because of the invalid message queue identifier): errno=22,qid=755761154,buf=11426968,bytes=4568,type=-1073741824,flag=0
013942.vmpodlqta004!BBL.1652.2147916896.0: LIBTUX_CAT:271: ERROR: System lock semop failure, key = 123489 (errno = 22)
013942.vmpodlqta004!BBL.1652.2147916896.0: LIBTUX_CAT:268: ERROR: Failed to stop serving
013942.vmpodlqta004!BBL.1652.2147916896.0: CMDTUX_CAT:26: INFO: The BBL is exiting system


Trace File shows:
---------
NOTE: They were inexplicably opening a new persistent cursor here after the select from PSSTATUS. After this proper commits and disconnects quit happening.
PSBRKDSP_dflt.1023 (0) 1-1198 11.05.37 0.000146 Cur#1.1023.SLQT2J RC=0 Dur=0.000124 COM Stmt=SELECT DBID FROM PSSTATUS
PSBRKDSP_dflt.1023 (0) 1-1199 11.05.37 0.001442 Cur#1.1023.SLQT2J RC=0 Dur=0.001431 EXE
PSBRKDSP_dflt.1023 (0) 1-1200 11.05.37 0.000012 Cur#1.1023.SLQT2J RC=0 Dur=0.000002 Fetch
PSBRKDSP_dflt.1023 (0) 1-1201 11.05.37 0.001067 Cur#2.1023.notSamTran RC=0 Dur=0.000008 Open Cursor Handle=00000000064E3F20
PSBRKDSP_dflt.1023 (0) 1-1202 11.05.37 0.000012 Cur#2.1023.SLQT2J RC=0 Dur=0.000002 GET type=3003 cursor=persistent
PSBRKDSP_dflt.1023 (0) 1-1203 11.05.37 0.000013 Cur#2.1023.SLQT2J RC=0 Dur=0.000003 Disconnect
PSBRKDSP_dflt.1023 (0) 1-1204 11.05.37 0.002718 Cur#2.1023.notSamTran RC=0 Dur=0.000008 Open Cursor Handle=00000000064E3F20
PSBRKDSP_dflt.1023 (0) 1-1205 11.05.37 0.000129 Cur#2.1023.SLQT2J RC=0 Dur=0.000115 COM Stmt=SELECT RELEASELABEL, RELEASEDTTM FROM PSRELEASE ORDER BY RELEASEDTTM DESC


The following is a trace of a working environment. Note cursor does not change. :....
0.000095 COM Stmt=SELECT DBID FROM PSSTATUS
PSBRKDSP_dflt.2846 (0) 1-1288 13.58.09 0.000458 Cur#1.2846.HCM91 RC=0 Dur=0.000452 EXE
PSBRKDSP_dflt.2846 (0) 1-1289 13.58.09 0.000007 Cur#1.2846.HCM91 RC=0 Dur=0.000001 Fetch
PSBRKDSP_dflt.2846 (0) 1-1290 13.58.09 0.000068 Cur#1.2846.HCM91 RC=0 Dur=0.000047 COM Stmt=SELECT 'X' FROM PSCLASSDEFN WHERE CLASSID IN (SELECT OPRCLASS FROM PSOPRCLS WHERE OPRID = :1) AND STARTAPPSERVER = 1

Changes

Cause

My Oracle Support provides customers with access to over a million knowledge articles and a vibrant support community of peers and Oracle experts.