Dispatcher running but Dialog Queue standstill, JA...

michael_swistowski · ‎11-12-2013

Hello!

After the first synchronising SLD and LMDB during SolMan 7.1 Setup (SOLMAN_SETUP), that was running some hours, I got the message in SAP Console:

"Dispatcher running but Dialog Queue standstill, JAVA: Synchronising binaries" and no GUI Connection, System is yellow, JAVA in der Console is not available.

Here disp_work process:

---------------------------------------------------

trc file: "dev_disp.new", trc level: 1, release: "720"

---------------------------------------------------

sysno 00

sid SOL

systemid 390 (AMD/Intel x86_64 with Linux)

relno 7200

patchlevel 0

patchno 401

intno 20020600

make single threaded, Unicode, 64 bit, optimized

profile /usr/sap/SOL/SYS/profile/SOL_DVEBMGS00_solman

pid 13217

kernel runs with dp version 138000(ext=119000) (@(#) DPLIB-INT-VERSION-138000-UC)

length of sys_adm_ext is 588 bytes

*** SWITCH TRC-HIDE on ***

***LOG Q00=> DpSapEnvInit, DPStart (00 13217) [dpxxdisp.c 1320]

shared lib "dw_xml.so" version 401 successfully loaded

shared lib "dw_xtc.so" version 401 successfully loaded

shared lib "dw_stl.so" version 401 successfully loaded

shared lib "dw_gui.so" version 401 successfully loaded

shared lib "dw_mdm.so" version 401 successfully loaded

shared lib "dw_rndrt.so" version 401 successfully loaded

shared lib "dw_abp.so" version 401 successfully loaded

shared lib "dw_sym.so" version 401 successfully loaded

shared lib "dw_aci.so" version 401 successfully loaded

rdisp/softcancel_sequence : -> 0,5,-1

use internal message server connection to port 3900

rdisp/dynamic_wp_check : 1

rdisp/calculateLoadAverage : 1

MtxInit: 30000 0 0

DpSysAdmExtInit: ABAP is active

DpSysAdmExtInit: VMC (JAVA VM in WP) is not active

DpIPCInit2: write dp-profile-values into sys_adm_ext

DpIPCInit2: start server >solman_SOL_00 <

DpShMCreate: sizeof(wp_adm) 42864 (2256)

DpShMCreate: sizeof(tm_adm) 5581368 (27768)

DpShMCreate: sizeof(wp_ca_adm) 80000 (80)

DpShMCreate: sizeof(appc_ca_adm) 80000 (80)

DpCommTableSize: max/headSize/ftSize/tableSize=500/8/1376056/1376064

DpShMCreate: sizeof(comm_adm) 1376064 (2744)

DpSlockTableSize: max/headSize/ftSize/fiSize/tableSize=0/0/0/0/0

DpShMCreate: sizeof(slock_adm) 0 (296)

DpFileTableSize: max/headSize/ftSize/tableSize=0/0/0/0

DpShMCreate: sizeof(file_adm) 0 (80)

DpShMCreate: sizeof(vmc_adm) 0 (2304)

DpShMCreate: sizeof(wall_adm) (40056/42872/80/192)

DpShMCreate: sizeof(gw_adm) 48

DpShMCreate: sizeof(j2ee_adm) 3952

DpShMCreate: SHM_DP_ADM_KEY (addr: 7fe32ce27000, size: 7261304)

DpShMCreate: allocated sys_adm at 7fe32ce27008

DpShMCreate: allocated wp_adm_list at 7fe32ce2a168

DpShMCreate: allocated wp_adm at 7fe32ce2a350

DpShMCreate: allocated tm_adm_list at 7fe32ce34ac8

DpShMCreate: allocated tm_adm at 7fe32ce34b10

DpShMCreate: allocated wp_ca_adm at 7fe32d387550

DpShMCreate: allocated appc_ca_adm at 7fe32d39add8

DpShMCreate: allocated comm_adm at 7fe32d3ae660

DpShMCreate: system runs without slock table

DpShMCreate: system runs without file table

DpShMCreate: allocated vmc_adm_list at 7fe32d4fe5a8

DpShMCreate: system runs without vmc_adm

DpShMCreate: allocated gw_adm at 7fe32d4fe650

DpShMCreate: allocated j2ee_adm at 7fe32d4fe688

DpShMCreate: allocated ca_info at 7fe32d4ff600

DpShMCreate: allocated wall_adm at 7fe32d4ff6a0

DpCommAttachTable: attached comm table (header=7fe32d3ae660/ft=7fe32d3ae668)

DpSysAdmIntInit: initialize sys_adm

rdisp/test_roll : roll strategy is DP_NORMAL_ROLL

dia token check not active (10 token)

MBUF state OFF

DpCommInitTable: init table for 500 entries

DpRqQInit: keep protect_queue / slots_per_queue 0 / 4001 in sys_adm

rdisp/queue_size_check_value : -> on,50,30,40,500,50,500,80

EmInit: MmSetImplementation( 2 ).

MM global diagnostic options set: 0

<ES> client 0 initializing ....

<ES> EsILock: use spinlock for locking

<ES> InitFreeList

<ES> block size is 4096 kByte.

Using implementation std

EsStdUnamFileMapInit: ES base = 0x7fe226758000

EsStdInit: Extended Memory 4096 MB allocated

Linux: Kernel supports shared memory disclaiming

Linux: using madvise(<pointer>, <size>, 9).

Linux: disclaiming for shared memory enabled

<ES> 1023 blocks reserved for free list.

ES initialized.

mm.dump: set maximum dump mem to 96 MB

DpVmcSetActive: set vmc state DP_VMC_NOT_ACTIVE

MPI: dynamic quotas disabled.

MPI init: pipes=4000 buffers=1279 reserved=383 quota=10%

J2EE server info

start = TRUE

state = STARTED

pid = 13246

argv[0] = /usr/sap/SOL/DVEBMGS00/exe/jcontrol

argv[1] = /usr/sap/SOL/DVEBMGS00/exe/jcontrol

argv[2] = pf=/usr/sap/SOL/SYS/profile/SOL_DVEBMGS00_solman

argv[3] = -DSAPSTART=1

argv[4] = -DCONNECT_PORT=65000

argv[5] = -DSAPSYSTEM=00

argv[6] = -DSAPSYSTEMNAME=SOL

argv[7] = -DSAPMYNAME=solman_SOL_00

argv[8] = -DSAPPROFILE=/usr/sap/SOL/SYS/profile/SOL_DVEBMGS00_solman

argv[9] = -DFRFC_FALLBACK=ON

argv[10] = -DFRFC_FALLBACK_HOST=localhost

start_lazy = 0

start_control = SAP J2EE startup framework

DpJ2eeStart: j2ee state = STARTED

rdisp/http_min_wait_dia_wp : 1 -> 1

***LOG CPS=> DpLoopInit, ICU ( 3.4 3.4 4.1) [dpxxdisp.c 1706]

***LOG Q0K=> DpMsAttach, mscon ( solman) [dpxxdisp.c 12674]

MBUF state LOADING

DpStartStopMsg: send start message (myname is >solman_SOL_00 <)

DpStartStopMsg: start msg sent

**START Linux Memory Parameter Check

virtual memory: hard-limit = UNLIMITED

virtual memory: soft-limit = UNLIMITED

core size: hard-limit = UNLIMITED

core size: soft-limit = 0 MB

data segment size: hard-limit = UNLIMITED

data segment size: soft-limit = UNLIMITED

stack size: hard-limit = UNLIMITED

stack size: soft-limit = 8 MB

max open files: hard-limit = 32800

max open files: soft-limit = 32800

Page Size: 4 KB

kernel.shmmax = 8796093022207 MB
kernel.shmall = 4503599627370495 MB

**END Linux Memory Parameter Check

CCMS: SemInMgt: Semaphore Management initialized by AlAttachShm_Doublestack.

CCMS: SemInit: Semaphore 38 initialized by AlAttachShm_Doublestack.

Tue Nov 12 09:16:29 2013

CCMS: start to initalize 3.X shared alert area (first segment).

DpMBufHwIdSet: set Hardware-ID

***LOG Q1C=> DpMBufHwIdSet [dpxxmbuf.c 1296]

MBUF state ACTIVE

DpWpBlksLow: max wp blocks in queue is 800 (80 %)

MBUF component UP

DpMsgProcess: 1 server in MBUF

DpAppcBlksLow: max appc blocks in queue is 500 (50 %)

Tue Nov 12 09:16:31 2013

DpJ2eeLogin: j2ee state = CONNECTED

-----------

dev_icm

[Thr 140055776761600] Tue Nov 12 09:16:39 2013

[Thr 140055776761600] HttpExtractArchive: files from archive /usr/sap/SOL/DVEBMGS00/exe/ITS.SAR in directory /usr/sap/SOL/DVEBMGS00/data/icmandir are up to date

[Thr 140055779403520] Tue Nov 12 09:17:30 2013

[Thr 140055779403520] *** WARNING => IcmCallAllSchedules: Schedule func 1 already running - avoid recursion [icxxsched_mt 481]

------------

I found errors also in files like this one:

work/std_bootstrap_ID4464400.out

--------------------------------------------------------------------------------

stdout/stderr redirect

--------------------------------------------------------------------------------

node name : dispatcher bootstrap

pid : 13246

system name : SOL

system nr. : 00

started at : Tue Nov 12 09:16:45 2013

***Warning: .hotspot_compiler file is present but has been ignored. Run with -XX:CompileCommandFile=.hotspot_compiler to load the file.

[Thr 140722821019392] Tue Nov 12 09:16:48 2013

[Thr 140722821019392] *** ERROR => JsfGetShmVmci: check failed: sRefs.statAccess > SFI_SMA_NOTINIT [jsfxxsproc.c 439]

[Thr 140722821019392] Tue Nov 12 09:16:49 2013

[Thr 140722821019392] *** ERROR => JsfGetShmVmci: check failed: sRefs.statAccess > SFI_SMA_NOTINIT [jsfxxsproc.c 439]

--------------------

Work/log_bootstrap_ID004464450.0.log

[Nov 12, 2013 9:16:54 AM ] --------------------------------------------------

[Nov 12, 2013 9:16:54 AM ] Bootstrap MODE:

[Nov 12, 2013 9:16:54 AM ] <SINGLE INSTANCE>

[Nov 12, 2013 9:16:54 AM ] determined by parameter [ID004464450].

[Nov 12, 2013 9:16:54 AM ] --------------------------------------------------

[Nov 12, 2013 9:16:56 AM ] Missing RunningMode property - runningin NORMAL mode.

[Nov 12, 2013 9:16:56 AM ] +----------------[ DB info ]----------------

[Nov 12, 2013 9:16:56 AM ] | Cluster ID in DB : ID4464450

[Nov 12, 2013 9:16:56 AM ] | Type : server

[Nov 12, 2013 9:16:56 AM ] | Installation Local Home : ./server0

[Nov 12, 2013 9:16:56 AM ] | OS : linuxx86_64

[Nov 12, 2013 9:16:56 AM ] | Unicode support : nuc

[Nov 12, 2013 9:16:56 AM ] | Bit-length : 64

[Nov 12, 2013 9:16:56 AM ] | Binaries Synch Status : 2

[Nov 12, 2013 9:16:56 AM ] | Database bin version : 251

[Nov 12, 2013 9:16:56 AM ] | Local bin version : 251

[Nov 12, 2013 9:16:56 AM ] +--------------------------------------------

[Nov 12, 2013 9:16:56 AM ] * Synchronizing configuration...

[Nov 12, 2013 9:16:56 AM ] No local properties available for [ApplicationThreadManager].

[Nov 12, 2013 9:16:56 AM ] No local properties available for [LicensingManager].

[Nov 12, 2013 9:16:56 AM ] No local properties available for [ClassLoaderManager].

[Nov 12, 2013 9:16:56 AM ] No local properties available for [PoolManager].

[Nov 12, 2013 9:16:56 AM ] No local properties available for [LogManager].

[Nov 12, 2013 9:16:56 AM ] No local properties available for [CacheManager].

[Nov 12, 2013 9:16:56 AM ] No local properties available for [IpVerificationManager].

[Nov 12, 2013 9:16:56 AM ] No local properties available for [kernel_shell_commands].

[Nov 12, 2013 9:16:56 AM ] No local properties available for [ThreadManager].

[Nov 12, 2013 9:16:56 AM ] No local properties available for [LockingManager].

[Nov 12, 2013 9:16:56 AM ] Synchronizing file [/usr/sap/SOL/DVEBMGS00/j2ee/cluster/server0/cfg/kernel/log-configuration.xml].

[Nov 12, 2013 9:16:56 AM ] ...Synched ok!

[Nov 12, 2013 9:16:56 AM ] Synchronizing file [/usr/sap/SOL/DVEBMGS00/j2ee/cluster/server0/cfg/kernel/enqt.pf].

[Nov 12, 2013 9:16:56 AM ] ...Synched ok!

[Nov 12, 2013 9:16:56 AM ] Synchronizing file [/usr/sap/SOL/DVEBMGS00/j2ee/cluster/server0/cfg/kernel/kernel.properties].

[Nov 12, 2013 9:16:56 AM ] ...Synched ok!

[Nov 12, 2013 9:16:56 AM ] Synchronizing file [/usr/sap/SOL/DVEBMGS00/j2ee/cluster/server0/cfg/kernel/hosts.txt].

[Nov 12, 2013 9:16:56 AM ] ...Synched ok!

[Nov 12, 2013 9:16:56 AM ] Synchronizing file [/usr/sap/SOL/DVEBMGS00/j2ee/cluster/server0/cfg/kernel/custom-log-configuration.xml].

[Nov 12, 2013 10:16:51...] Error synchronizing file [/usr/sap/SOL/DVEBMGS00/j2ee/cluster/server0/cfg/kernel/custom-log-configuration.xml].

com.sap.engine.frame.core.configuration.InvalidPersistentDataStreamException: Could not get file from DB.

at com.sap.engine.core.configuration.impl.PersistentDataInputStream.getStream(PersistentDataInputStream.java:84)

at com.sap.engine.core.configuration.impl.PersistentDataInputStream.read(PersistentDataInputStream.java:135)

at com.sap.engine.bootstrap.Synchronizer.getFile(Synchronizer.java:245)

at com.sap.engine.bootstrap.Synchronizer.getFile(Synchronizer.java:216)

at com.sap.engine.bootstrap.Synchronizer.getFiles(Synchronizer.java:555)

at com.sap.engine.bootstrap.Synchronizer.loadProperties(Synchronizer.java:536)

at com.sap.engine.bootstrap.Synchronizer.synchronizeProperties(Synchronizer.java:280)

at com.sap.engine.bootstrap.Bootstrap.getProperties(Bootstrap.java:784)

at com.sap.engine.bootstrap.Bootstrap.synchronize(Bootstrap.java:567)

at com.sap.engine.bootstrap.Bootstrap.makeUpdate(Bootstrap.java:971)

at com.sap.engine.bootstrap.Bootstrap.main(Bootstrap.java:947)

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

at java.lang.reflect.Method.invoke(Method.java:331)

at com.sap.engine.offline.OfflineToolStart.main(OfflineToolStart.java:81)

Caused by:

com.sap.dbtech.jdbc.exceptions.DatabaseException: [500] (at 4): Lock request timeout

at com.sap.dbtech.jdbc.exceptions.SQLExceptionSapDB.createException(SQLExceptionSapDB.java:244)

at com.sap.dbtech.jdbc.exceptions.SQLExceptionSapDB.generateDatabaseException(SQLExceptionSapDB.java:138)

at com.sap.dbtech.jdbc.packet.ReplyPacket.createException(ReplyPacket.java:69)

at com.sap.dbtech.jdbc.ConnectionSapDB.throwSQLError(ConnectionSapDB.java:1096)

at com.sap.dbtech.jdbc.ConnectionSapDB.execute(ConnectionSapDB.java:720)

at com.sap.dbtech.jdbc.ConnectionSapDB.execute(ConnectionSapDB.java:562)

at com.sap.dbtech.jdbc.CallableStatementSapDB.execute(CallableStatementSapDB.java:454)

at com.sap.dbtech.jdbc.CallableStatementSapDB.execute(CallableStatementSapDB.java:319)

at com.sap.dbtech.jdbc.CallableStatementSapDB.executeQuery(CallableStatementSapDB.java:763)

at com.sap.dbtech.jdbc.trace.PreparedStatement.executeQuery(PreparedStatement.java:161)

at com.sap.sql.jdbc.direct.DirectPreparedStatement.executeQuery(DirectPreparedStatement.java:282)

at com.sap.sql.jdbc.direct.DirectPreparedStatement.executeQuery(DirectPreparedStatement.java:249)

at com.sap.engine.core.configuration.impl.persistence.rdbms.DBAccessDefault.getFileEntry(DBAccessDefault.java:1005)

at com.sap.engine.core.configuration.impl.persistence.rdbms.FileLoader.getInputStream(FileLoader.java:33)

at com.sap.engine.core.configuration.impl.PersistentDataInputStream.getStream(PersistentDataInputStream.java:81)