Disp+work stop because of shared memory?

[Former Member]

Hello Gurus, I have an SAP server that will not start. It was running previously, but after a parameter update and an instance restart, I cannot get the dispatcher running.

System is Windows 2012 Server, MSSQL 2008 R2, 16 Core 132 GB RAM.

I believe it is related to shared memory overlapping somehow, but  I am not sure how to resolve or investigate. I have had issues previously with memory overlap halting SAP servers with Diagnostics Agents, but this server is not currently running any DAA. It is running SAPRouter and some SAP Web Dispatcher instances.

I will include my trace files below:

Please help!

DEV_W0:

---------------------------------------------------
trc file: "dev_w0", trc level: 1, release: "721"
---------------------------------------------------
*
*  ACTIVE TRACE LEVEL           1
*  ACTIVE TRACE COMPONENTS      all, MJ
*
M sysno      00
M sid        PRD
M systemid   562 (PC with Windows NT)
M relno      7210
M patchlevel 0
M patchno    100
M intno      20020600
M make       multithreaded, Unicode, 64 bit, optimized
M profile    \\SAPERP\sapmnt\PRD\SYS\profile\PRD_DVEBMGS00_SAPERP
M pid        7668
M
M  kernel runs with dp version 137000(ext=119000) (@(#) DPLIB-INT-VERSION-137000-UC)
M  length of sys_adm_ext is 588 bytes
M  ***LOG Q0Q=> tskh_init, WPStart (Workp. 0 7668) [dpxxdisp.c   1376]
I  MtxInit: 30000 0 0
M  DpSysAdmExtCreate: ABAP is active
M  DpSysAdmExtCreate: VMC (JAVA VM in WP) is not active
M  DpIPCInit2: read dp-profile-values from sys_adm_ext
M  DpShMCreate: sizeof(wp_adm) 42864 (2256)
M  DpShMCreate: sizeof(tm_adm) 5517056 (27448)
M  DpShMCreate: sizeof(wp_ca_adm) 64000 (64)
M  DpShMCreate: sizeof(appc_ca_adm) 64000 (64)
M  DpCommTableSize: max/headSize/ftSize/tableSize=500/16/1384064/1384080
M  DpShMCreate: sizeof(comm_adm) 1384080 (2744)
M  DpSlockTableSize: max/headSize/ftSize/fiSize/tableSize=0/0/0/0/0
M  DpShMCreate: sizeof(slock_adm) 0 (296)
M  DpFileTableSize: max/headSize/ftSize/tableSize=0/0/0/0
M  DpShMCreate: sizeof(file_adm) 0 (80)
M  DpShMCreate: sizeof(vmc_adm) 0 (2160)
M  DpShMCreate: sizeof(wall_adm) (41664/42896/64/192)
M  DpShMCreate: sizeof(gw_adm) 48
M  DpShMCreate: sizeof(j2ee_adm) 3952
M  DpShMCreate: SHM_DP_ADM_KEY (addr: 0000000000200050, size: 7174832)
M  DpShMCreate: allocated sys_adm at 0000000000200060
M  DpShMCreate: allocated wp_adm_list at 00000000002030B0
M  DpShMCreate: allocated wp_adm at 00000000002032A0
M  DpShMCreate: allocated tm_adm_list at 000000000020DA20
M  DpShMCreate: allocated tm_adm at 000000000020DA70
M  DpShMCreate: allocated wp_ca_adm at 0000000000750980
M  DpShMCreate: allocated appc_ca_adm at 0000000000760390
M  DpShMCreate: allocated comm_adm at 000000000076FDA0
M  DpShMCreate: system runs without slock table
M  DpShMCreate: system runs without file table
M  DpShMCreate: allocated vmc_adm_list at 00000000008C1C40
M  DpShMCreate: system runs without vmc_adm
M  DpShMCreate: allocated gw_adm at 00000000008C1CF0
M  DpShMCreate: allocated j2ee_adm at 00000000008C1D30
M  DpShMCreate: allocated ca_info at 00000000008C2CB0
M  DpShMCreate: allocated wall_adm at 00000000008C2D40
M  DpCommAttachTable: attached comm table (header=000000000076FDA0/ft=000000000076FDB0)
M  DpRqQInit: use protect_queue / slots_per_queue 0 / 2001 from sys_adm
M  rdisp/queue_size_check_value :  -> on,50,30,40,500,50,500,80
X  EmInit: MmSetImplementation( 2 ).
X  MM global diagnostic options set: 0
X  <ES> client 0 initializing ....
X  <ES> EsILock: use spinlock for locking
X  Using implementation view
X  <EsNT> Using memory model view.
M  <EsNT> Memory Reset disabled as NT default
X  ES initialized.
X  mm.dump: set maximum dump mem to 96 MB
M  DpVmcSetActive: set vmc state DP_VMC_NOT_ACTIVE
M 
M Fri May 16 01:23:14 2014
M  ThStart: taskhandler started
M  ThInit: initializing DIA work process W0
M 
M Fri May 16 01:23:15 2014
M  ThInit: running on host SAPERP
M 
M Fri May 16 01:23:16 2014
M  calling db_connect ...
B  Loading DB library 'E:\usr\sap\PRD\DVEBMGS00\exe\dbmssslib.dll' ...
B  Library 'E:\usr\sap\PRD\DVEBMGS00\exe\dbmssslib.dll' loaded
B  Version of 'E:\usr\sap\PRD\DVEBMGS00\exe\dbmssslib.dll' is "721.02", patchlevel (0.44)
C  Callback functions for dynamic profile parameter registered
C  Thread ID:4168
C  Thank You for using the SLODBC-interface
C  Using dynamic link library 'E:\usr\sap\PRD\DVEBMGS00\exe\dbmssslib.dll'
C  dbmssslib.dll patch info
C    SAP patchlevel  0
C    SAP patchno  100
C    Last MSSQL DBSL patchlevel 0
C    Last MSSQL DBSL patchno         44
C    Last MSSQL DBSL patchcomment DBSL support for Microsoft ODBC Driver 11 for SQL Server (1816426)
C  ODBC Driver chosen: SQL Server Native Client 11.0 native
C  lpc:(local) connection used on SAPERP
C  lpc:(local) connection used on SAPERP
C  Driver: sqlncli11.dll Driver release: 11.00.3000
C  GetDbRelease: 11.00.3339.00
C  GetDbRelease: Got DB release numbers (11,0,3339,0)
B  Connection 0 opened (DBSL handle 0)
M  ThInit: db_connect o.k.
M  ICT: exclude compression: *.zip,*.rar,*.arj,*.z,*.gz,*.tar,*.lzh,*.cab,*.hqx,*.ace,*.jar,*.ear,*.war,*.css,*.pdf,*.gzip,*.uue,*.bz2,*.iso,*.sda,*.sar,*.gif,*.png,*.swc,*.swf
I 
I Fri May 16 01:23:17 2014
I  MtxInit: 0 0 0
M  SHM_PRES_BUF (addr: 0000000018030050, size: 4400000)
M  SHM_ROLL_AREA (addr: 000007FFDDAB0050, size: 268435456)
M  SHM_PAGING_AREA (addr: 0000000018470050, size: 134217728)
M  SHM_ROLL_ADM (addr: 0000000020480050, size: 2767448)
M  SHM_PAGING_ADM (addr: 0000000020730050, size: 787488)
M  ThCreateNoBuffer allocated 548152 bytes for 1000 entries at 0000000020800050
M  ThCreateNoBuffer index size: 3000 elems
M  ThCreateVBAdm allocated 31056 bytes (50 server) at 0000000000910050
X  EmInit: MmSetImplementation( 2 ).
X  MM global diagnostic options set: 0
X  <ES> client 0 initializing ....
X  Using implementation view
X  ES initialized.
X  mm.dump: set maximum dump mem to 96 MB
B 
B Fri May 16 01:23:18 2014
B  db_con_shm_ini:  WP_ID = 0, WP_CNT = 19, CON_ID = -1
B  dbtbxbuf: Buffer TABL  (addr: 0000000027280160, size: 90000000, end: 000000002C854BE0)
B  dbtbxbuf: Buffer TABLP (addr: 000000002C860160, size: 20480000, end: 000000002DBE8160)
B  dbsync[db_syinit]: successfully attached to shared memory, sync_adm_p = 0000000011BE0050
B  dbsync[db_syinit]: Buffer synchronisation started with
B    sync_concept      = SEQ_NR
B    sendon            = 1
B    bufreftime        = 120
B    max_gap_wait_time = 60
B    ddlog_del_time    = 60
B    last_counter      = 702514
B    oldest_gap        = (2147483647,00000000000000)
B    time_of_last_sync = 20140516012317
B    MySysId           = 'SAPERP              00'
B  dbexpbuf[EXP_SHB]: buffer EIBUF installed with
B    semkey             = 35
B    shmkey             = 54
B    wp_n               = 19
B    sclass             = 0
B    block_length       = 256
B    max_objects        = 2000
B    max_obj_size       = 859872
B    pref_obj_size      = 0
B    est_large_obj_size = 16384
B    free_vec_lg        = 65
B    hash_vec_size      = 4001
B    buffer_l           = 4194304
B    max_blocks         = 13438
B    free_blocks        = 13438
B    mutex_n            = 4001
B    max_mtx_wait_time  = 17000
B    recovery_delay     = 500000
B    tracing            = 0
B    force_checks       = 0
B    protect_shm        = 0
B  dbexpbuf[EXP_SHM]: buffer ESM   installed with
B    semkey             = 56
B    shmkey             = 65
B    wp_n               = 19
B    sclass             = 0
B    block_length       = 256
B    max_objects        = 2000
B    max_obj_size       = 859872
B    pref_obj_size      = 0
B    est_large_obj_size = 16384
B    free_vec_lg        = 65
B    hash_vec_size      = 4001
B    buffer_l           = 4194304
B    max_blocks         = 13438
B    free_blocks        = 13438
B    mutex_n            = 4001
B    max_mtx_wait_time  = 17000
B    recovery_delay     = 500000
B    tracing            = 0
B    force_checks       = 0
B    protect_shm        = 0
B  dbexpbuf[EXP_CUA]: buffer CUA   installed with
B    semkey             = 30
B    shmkey             = 47
B    wp_n               = 19
B    sclass             = 10
B    block_length       = 512
B    max_objects        = 1500
B    max_obj_size       = 626016
B    pref_obj_size      = 0
B    est_large_obj_size = 98304
B    free_vec_lg        = 193
B    hash_vec_size      = 3001
B    buffer_l           = 3072000
B    max_blocks         = 4892
B    free_blocks        = 4892
B    mutex_n            = 3001
B    max_mtx_wait_time  = 17000
B    recovery_delay     = 500000
B    tracing            = 0
B    force_checks       = 0
B    protect_shm        = 0
B  dbexpbuf[EXP_OTR]: buffer OTR   installed with
B    semkey             = 55
B    shmkey             = 64
B    wp_n               = 19
B    sclass             = 13
B    block_length       = 256
B    max_objects        = 2000
B    max_obj_size       = 859872
B    pref_obj_size      = 0
B    est_large_obj_size = 20480
B    free_vec_lg        = 81
B    hash_vec_size      = 4001
B    buffer_l           = 4194304
B    max_blocks         = 13438
B    free_blocks        = 13438
B    mutex_n            = 4001
B    max_mtx_wait_time  = 17000
B    recovery_delay     = 500000
B    tracing            = 0
B    force_checks       = 0
B    protect_shm        = 0
I  MPI: dynamic quotas disabled.
I  MPI init: pipes=4000 buffers=1279 reserved=383 quota=10%
M  rdisp/thwpsf_critical_path : -1 -> 0
M  CCMS: SemInMgt: Semaphore Management initialized by AlAttachShm_Doublestack.
M  CCMS: SemInit: Semaphore 38 initialized by AlAttachShm_Doublestack.
G  RelWritePermissionForShm( pLocation = 120, pEnforce = 0 )
G  GetWritePermissionForShm( pLocation =  99, pEnforce = 1 )
G  RelWritePermissionForShm( pLocation = 100, pEnforce = 1 )
S  *** init spool environment
S  TSPEVJOB updates outside critical section: event_update_nocsec = 1
S  initialize debug system
T  Stack direction is downwards.
T  debug control: prepare exclude for printer trace
T  new memory block 0000000034052380
S  spool kernel/ddic check: Ok
S  using table TSP02FX for frontend printing
S  1 spool work process(es) found
S  frontend print via spool service enabled
S  printer list size is 150
S  printer type list size is 50
S  queue size (profile)   = 300
S  hostspool list size = 3000
S  option list size is 30
S      found processing queue enabled
S  found spool memory service RSPO-RCLOCKS at 00000000382B00D0
S  doing lock recovery
S  setting server cache root
S  found spool memory service RSPO-SERVERCACHE at 00000000382B06A0
S    using messages for server info
S  size of spec char cache entry: 297032 bytes (timeout 100 sec)
S  size of open spool request entry: 2512 bytes
S  immediate print option for implicitely closed spool requests is disabled
A  ***GENER* Trace switched on ***
A 
A  ---PXA-------------------------------------------
A  PXA INITIALIZATION
A  PXA: Locked PXA-Semaphore.
A  System page size: 4kb, total admin_size: 23104kb, dir_size: 22312kb.
A  Attached to PXA (address 000007FFEDAE0050, size 300000K, 1 fragments of 276896K )
A  PXA allocated (address 000007FFEDAE0050, size 300000K)
A  abap/pxa = shared protect gen_remote
A  PXA: checking structure sizes: 752|272|16
A  PXA INITIALIZATION FINISHED
A  ---PXA-------------------------------------------
A 
A  ATRA: pfclock execution time = 0
A  abap/force_local_update_task=0
A  ABAP ShmAdm attached (addr=000007DFDF142000 leng=20955136 end=000007DFE053E000)
A  >> Shm MMADM area (addr=000007DFDF639B80 leng=242240 end=000007DFDF674DC0)
A  >> Shm MMDAT area (addr=000007DFDF675000 leng=15503360 end=000007DFE053E000)
A  RFC Destination> destination SAPERP_PRD_00 host SAPERP system PRD systnr 0 (SAPERP_PRD_00)
A  RFC Options> H=SAPERP,S=00,d=2,
A  RFC FRFC> fallback activ but this is not a central instance.
A   
A  RFC rfc/signon_error_log = -1
A  RFC rfc/dump_connection_info = 0
A  RFC rfc/dump_client_info = 0
A  RFC rfc/cp_convert/ignore_error = 1
A  RFC rfc/cp_convert/conversion_char = 23
A  RFC rfc/wan_compress/threshold = 251
A  RFC rfc/recorder_pcs not set, use defaule value: 2
A  RFC rfc/delta_trc_level not set, use default value: 0
A  RFC rfc/no_uuid_check not set, use default value: 0
H  HTTP> Parameter icf/ssocookie_mandatory set to 0
B  dbtran INFO (init_connection '<DEFAULT>' [MSSQL:721.02]):
B   max_blocking_factor       =  50,  min_blocking_factor         =   5,
B   max_in_blocking_factor    = 255,  min_in_blocking_factor      =  10,
B   max_union_blocking_factor =  50,  min_union_blocking_factor   =   5,
B   prefer_union_all          =   1,  prefer_join                 =   1,
B   prefer_fix_blocking       =   0,  prefer_in_itab_opt          =   0,
B   convert AVG               =   1,  alias table FUPD            =   0,
B   escape_as_literal         =   0,                                  
B   select *                  =0x00,  character encoding          = STD / []:X,
B   use_hints                 = abap->1, dbif->0x1, upto->0
M  ThrCreateShObjects allocated 39514 bytes at 0000000011C00050
Y  dyWpInit
Y    ztta/dynpro_ara 800000
Y    ztta/cua_ara    500000
Y    ztta/diag_ara   250000
N  SsfSapSecin: getenv(SECUDIR)=="E:\usr\sap\PRD\DVEBMGS00/sec"
N 
N  =================================================
N  === SSF INITIALIZATION:
N  ===...SSF Security Toolkit name SAPSECULIB .
N  ===...SSF library is E:\usr\sap\PRD\DVEBMGS00\exe\sapcrypto.dll .
N  ===...SSF default hash algorithm is SHA1 .
N  ===...SSF default symmetric encryption algorithm is DES-CBC .
N  ===...SECUDIR="E:\usr\sap\PRD\DVEBMGS00/sec"
N  ===...loading of Security Toolkit successfully completed.
N  ===   SAPCRYPTOLIB  5.5.5C pl32  (Apr  2 2011) MT-safe
N  =================================================
N 
N Fri May 16 01:23:20 2014
N  MskiInitLogonTicketCacheHandle: Logon Ticket cache pointer retrieved from shared memory.
N  MskiInitLogonTicketCacheHandle: Workprocess runs with Logon Ticket cache.
M  JrfcVmcRegisterNativesDriver o.k.
W  =================================================
W  === ipl_Init() called
W    ITS Plugin: Path dw_gui
W    ITS Plugin: Description ITS Plugin - ITS rendering DLL
W    ITS Plugin: sizeof(SAP_UC) 2
W    ITS Plugin: Release: 721, [7210.0.100.20020600]
W    ITS Plugin: Int.version, [34]
W    ITS Plugin: Feature set: [31]
W    ===... Calling itsp_Init in external dll ===>
W  === ipl_Init() returns 0, ITSPE_OK: OK
W  =================================================
N  SignInit: successfully obtained handle for Security Context cache
N  SPNegoInit: SPNego disabled ("spnego/enable" not set to 1)
N  VSI: WP init in ABAP VM completed with rc=0
E  EnqLockTableSizeCalculate: session quota = 100%
E  EnqLockTableAttach2: attach to lock table (size = 33554432)
E  EnqLockTableMapToLocalContext: enque/use_pfclock2 = FALSE
E  EnqId_Initialize: local EnqId initialization o.k.
M 
M Fri May 16 01:23:40 2014
M  *** ERROR => ThPlgConnectToIcm: IcmReadAck failed (-8, ni_rc=-6) [thxxplg.c    5172]
M  in_ThErrHandle: 1
M  *** ERROR => ThStart: connect to icman (step 1, th_errno 2, action 3, level 1) [thxxhead.c   11348]
M 
M  Info for wp 0
M 
M    pid = 7668
M    severity = 0
M    status = 0
M    stat = WP_NEW
M    waiting_for = NO_WAITING
M    reqtype = DP_RQ_DIAWP
M    act_reqtype = NO_REQTYPE
M    req.req_info =
M    req.tid = -1
M    req.uid = 4294967295
M    req.mode = 255
M    req.len = 0
M    req.rq_id = 65535
M    req.rq_source =
M    last_tid = 0
M    last_uid = 0
M    last_mode = 0
M    act_cs_count = 0
M    csTrack = 0
M    csTrackRwExcl = 0
M    csTrackRwShrd = 0
M    mode_cleaned_counter = 0
M    control_flag = 0
M    int_checked_resource(RFC) = 0
M    ext_checked_resource(RFC) = 0
M    int_checked_resource(HTTP) = 0
M    ext_checked_resource(HTTP) = 0
M    report = >                                        <
M    action = 0
M    tab_name = >                              <
M    attachedVm = no VM
M 
M  ThIErrHandle: current request:
M 
M  -IN-- sender_id ?                 tid  -1    wp_ca_blk   -1      wp_id -1
M  -IN-- action    -                 uid  -1    appc_ca_blk -1      type  -   
M  -IN-- new_stat  NO_CHANGE         mode 255   len         0       rq_id -1
M  PfStatDisconnect: disconnect statistics
M  Entering TH_CALLHOOKS
M  ThCallHooks: call hook >TrThHookFunc< for event BEFORE_DUMP
M  TrThHookFunc: called for WP dump
M  ThCallHooks: hook >TrThHookFunc< o.k.
M  ThCallHooks: call hook >ThrSaveSPAFields< for event BEFORE_DUMP
M  ThrSaveSPAFields: save spa fields
M  ThrSaveSPAFields: not an update task, no update info saved
M  ThrSaveSPAFields: not a batch task, field zttabtckey not saved
M  ThCallHooks: hook >ThrSaveSPAFields< o.k.
M  ThCallHooks: call hook >ThrBtcCallLgCl< for event BEFORE_DUMP
M  ThCallHooks: hook >ThrBtcCallLgCl< o.k.
M  ThIErrHandle: entering ThSetStatError
M  ThIErrHandle: do not call ThrCoreInfo (no_core_info=0, in_dynp_env=0)
M  Entering ThReadDetachMode
M  call ThrShutDown (1)...
M  ***LOG Q02=> wp_halt, WPStop (Workp. 0 7668) [dpnttool.c   339]

DEV_DISP:

---------------------------------------------------
trc file: "dev_disp", trc level: 1, release: "721"
---------------------------------------------------
sysno      00
sid        PRD
systemid   562 (PC with Windows NT)
relno      7210
patchlevel 0
patchno    100
intno      20020600
make       multithreaded, Unicode, 64 bit, optimized
profile    \\SAPERP\sapmnt\PRD\SYS\profile\PRD_DVEBMGS00_SAPERP
pid        4924


kernel runs with dp version 137000(ext=119000) (@(#) DPLIB-INT-VERSION-137000-UC)
length of sys_adm_ext is 588 bytes
*** SWITCH TRC-HIDE on ***
***LOG Q00=> DpSapEnvInit, DPStart (00 4924) [dpxxdisp.c   1314]
  shared lib "dw_xml.dll" version 100 successfully loaded
  shared lib "dw_xtc.dll" version 100 successfully loaded
  shared lib "dw_stl.dll" version 100 successfully loaded
  shared lib "dw_gui.dll" version 100 successfully loaded
  shared lib "dw_mdm.dll" version 100 successfully loaded
  shared lib "dw_rndrt.dll" version 100 successfully loaded
  shared lib "dw_abp.dll" version 100 successfully loaded
  shared lib "dw_sym.dll" version 100 successfully loaded
  shared lib "dw_aci.dll" version 100 successfully loaded
rdisp/softcancel_sequence :  -> 0,5,-1
use internal message server connection to port 3900
rdisp/dynamic_wp_check : 1
rdisp/calculateLoadAverage : 1


Fri May 16 01:23:12 2014
*** WARNING => DpNetCheck: NiAddrToHost(1.0.0.0) took 4 seconds
***LOG GZZ=> 1 possible network problems detected - check tracefile and adjust the DNS settings [dpxxtool2.c  6438]
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 >SAPERP_PRD_00                           <
DpShMCreate: sizeof(wp_adm) 42864 (2256)
DpShMCreate: sizeof(tm_adm) 5517056 (27448)
DpShMCreate: sizeof(wp_ca_adm) 64000 (64)
DpShMCreate: sizeof(appc_ca_adm) 64000 (64)
DpCommTableSize: max/headSize/ftSize/tableSize=500/16/1384064/1384080
DpShMCreate: sizeof(comm_adm) 1384080 (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 (2160)
DpShMCreate: sizeof(wall_adm) (41664/42896/64/192)
DpShMCreate: sizeof(gw_adm) 48
DpShMCreate: sizeof(j2ee_adm) 3952
DpShMCreate: SHM_DP_ADM_KEY (addr: 0000000005460050, size: 7174832)
DpShMCreate: allocated sys_adm at 0000000005460060
DpShMCreate: allocated wp_adm_list at 00000000054630B0
DpShMCreate: allocated wp_adm at 00000000054632A0
DpShMCreate: allocated tm_adm_list at 000000000546DA20
DpShMCreate: allocated tm_adm at 000000000546DA70
DpShMCreate: allocated wp_ca_adm at 00000000059B0980
DpShMCreate: allocated appc_ca_adm at 00000000059C0390
DpShMCreate: allocated comm_adm at 00000000059CFDA0
DpShMCreate: system runs without slock table
DpShMCreate: system runs without file table
DpShMCreate: allocated vmc_adm_list at 0000000005B21C40
DpShMCreate: system runs without vmc_adm
DpShMCreate: allocated gw_adm at 0000000005B21CF0
DpShMCreate: allocated j2ee_adm at 0000000005B21D30
DpShMCreate: allocated ca_info at 0000000005B22CB0
DpShMCreate: allocated wall_adm at 0000000005B22D40
DpCommAttachTable: attached comm table (header=00000000059CFDA0/ft=00000000059CFDB0)
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 / 2001 in sys_adm


Fri May 16 01:23:13 2014
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.
<ES> Info: em/initial_size_MB( 134981MB) not multiple of em/blocksize_KB( 4096KB)
<ES> Info: em/initial_size_MB rounded up to 134984MB
Using implementation view
<EsNT> Using memory model view.
<EsNT> Memory Reset disabled as NT default
<ES> 33745 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%
rdisp/http_min_wait_dia_wp : 1 -> 1
***LOG CPS=> DpLoopInit, ICU ( 4.0.1 4.0.1 5.1) [dpxxdisp.c   1700]


Fri May 16 01:23:40 2014
***LOG Q0K=> DpMsAttach, mscon ( SAPERP) [dpxxdisp.c   12667]
MBUF state LOADING
DpStartStopMsg: send start message (myname is >SAPERP_PRD_00                           <)
DpStartStopMsg: start msg sent
CCMS: SemInMgt: Semaphore Management initialized by AlAttachShm_Doublestack.
CCMS: SemInit: Semaphore 38 initialized by AlAttachShm_Doublestack.
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 %)
*** ERROR => DpIcmMsgProcess: IcmRecMsg (rc=-8,-6) [dpxxdisp.c   19121]


Fri May 16 01:24:20 2014
*** ERROR => DpHdlDeadWp: W0 (pid 7668) died (severity=0, status=0) [dpxxwp.c     1729]
*** ERROR => DpHdlDeadWp: W1 (pid 7456) died (severity=0, status=0) [dpxxwp.c     1729]
*** ERROR => DpHdlDeadWp: W2 (pid 8096) died (severity=0, status=0) [dpxxwp.c     1729]
*** ERROR => DpHdlDeadWp: W3 (pid 4376) died (severity=0, status=0) [dpxxwp.c     1729]
*** ERROR => DpHdlDeadWp: W4 (pid 3000) died (severity=0, status=0) [dpxxwp.c     1729]
*** ERROR => DpHdlDeadWp: W5 (pid 3520) died (severity=0, status=0) [dpxxwp.c     1729]
*** ERROR => DpHdlDeadWp: W6 (pid 7024) died (severity=0, status=0) [dpxxwp.c     1729]
*** ERROR => DpHdlDeadWp: W7 (pid 6172) died (severity=0, status=0) [dpxxwp.c     1729]
*** ERROR => DpHdlDeadWp: W8 (pid 6576) died (severity=0, status=0) [dpxxwp.c     1729]
*** ERROR => DpHdlDeadWp: W9 (pid 7756) died (severity=0, status=0) [dpxxwp.c     1729]
*** ERROR => DpHdlDeadWp: W10 (pid 624) died (severity=0, status=0) [dpxxwp.c     1729]
*** ERROR => DpHdlDeadWp: W11 (pid 7468) died (severity=0, status=0) [dpxxwp.c     1729]
*** ERROR => DpHdlDeadWp: W12 (pid 1176) died (severity=0, status=0) [dpxxwp.c     1729]
*** ERROR => DpHdlDeadWp: W13 (pid 6812) died (severity=0, status=0) [dpxxwp.c     1729]
*** ERROR => DpHdlDeadWp: W14 (pid 6968) died (severity=0, status=0) [dpxxwp.c     1729]
*** ERROR => DpHdlDeadWp: W15 (pid 5036) died (severity=0, status=0) [dpxxwp.c     1729]
*** ERROR => DpHdlDeadWp: W16 (pid 5576) died (severity=0, status=0) [dpxxwp.c     1729]
*** DP_FATAL_ERROR => DpWPCheck: no more work processes
*** DISPATCHER EMERGENCY SHUTDOWN ***
increase tracelevel of WPs
NiWait: sleep (10000ms) ...
NiISelect: timeout 10000ms
NiISelect: maximum fd=1445
NiISelect: read-mask is NULL
NiISelect: write-mask is NULL
Fri May 16 01:24:30 2014
NiISelect: TIMEOUT occured (10000ms)
dump system status
Workprocess Table (long) Fri May 16 07:24:30 2014
========================


No Type  Pid    Status  Cause Start Rstr  Err Sem Time Program          Cl  User         Action                    Table
-------------------------------------------------------------------------------------------------------------------------------
0 DIA       -1 Ended         no    no     1   0    0                                    NO_ACTION                          
1 DIA       -1 Ended         no    no     1   0    0                                    NO_ACTION                          
2 DIA       -1 Ended         no    no     1   0    0                                    NO_ACTION                          
3 DIA       -1 Ended         no    no     1   0    0                                    NO_ACTION                          
4 DIA       -1 Ended         no    no     1   0    0                                    NO_ACTION                          
5 DIA       -1 Ended         no    no     1   0    0                                    NO_ACTION                          
6 DIA       -1 Ended         no    no     1   0    0                                    NO_ACTION                          
7 DIA       -1 Ended         no    no     1   0    0                                    NO_ACTION                          
8 DIA       -1 Ended         no    no     1   0    0                                    NO_ACTION                          
9 DIA       -1 Ended         no    no     1   0    0                                    NO_ACTION                          
10 UPD       -1 Ended         no    no     1   0    0                                    NO_ACTION                          
11 ENQ       -1 Ended         no    no     1   0    0                                    NO_ACTION                          
12 BTC       -1 Ended         no    no     1   0    0                                    NO_ACTION                          
13 BTC       -1 Ended         no    no     1   0    0                                    NO_ACTION                          
14 BTC       -1 Ended         no    no     1   0    0                                    NO_ACTION                          
15 SPO       -1 Ended         no    no     1   0    0                                    NO_ACTION                          
16 UP2       -1 Ended         no    no     1   0    0                                    NO_ACTION                          
Dispatcher Queue Statistics Fri May 16 07:24:30 2014
===========================


+------+--------+--------+--------+------------+------------+
|  Typ |    now |   high |    max | writes     |  reads     |
+------+--------+--------+--------+------------+------------+
| NOWP |      1 |     33 |   2000 |         43 |         42 |
+------+--------+--------+--------+------------+------------+
|  DIA |      5 |      5 |   2000 |          5 |          0 |
+------+--------+--------+--------+------------+------------+
|  UPD |      1 |      1 |   2000 |          1 |          0 |
+------+--------+--------+--------+------------+------------+
|  ENQ |      0 |      0 |   2000 |          0 |          0 |
+------+--------+--------+--------+------------+------------+
|  BTC |      0 |      0 |   2000 |          0 |          0 |
+------+--------+--------+--------+------------+------------+
|  SPO |      0 |      0 |   2000 |          0 |          0 |
+------+--------+--------+--------+------------+------------+
|  UP2 |      0 |      0 |   2000 |          0 |          0 |
+------+--------+--------+--------+------------+------------+


max_rq_id 40
wake_evt_udp_now 0


wake events       total    40,  udp     5 ( 12%),  shm    35 ( 87%)
since last update total    40,  udp     5 ( 12%),  shm    35 ( 87%)


DpGetLoadAverage: la1[1] = 0.000000 / -1.000000 %
DpGetLoadAverage: la5[1] = 0.000000 / -1.000000 %
DpGetLoadAverage: la15[1] = 0.055556 / -1.000000 %
Dispatcher Load Statistics
+------+---------+---------+---------+
|  Typ |     LA1 |     LA5 |    LA15 |
+------+---------+---------+---------+
|  DIA |   0.000 |   0.000 |   0.056 |
+------+---------+---------+---------+
DpGetLoadAverage: la1[2] = 0.000000 / -1.000000 %
DpGetLoadAverage: la5[2] = 0.000000 / -1.000000 %
DpGetLoadAverage: la15[2] = 0.011111 / -1.000000 %
|  UPD |   0.000 |   0.000 |   0.011 |
+------+---------+---------+---------+
DpGetLoadAverage: la1[3] = 0.000000 / -1.000000 %
DpGetLoadAverage: la5[3] = 0.000000 / -1.000000 %
DpGetLoadAverage: la15[3] = 0.000000 / -1.000000 %
|  ENQ |   0.000 |   0.000 |   0.000 |
+------+---------+---------+---------+
DpGetLoadAverage: la1[4] = 0.000000 / -1.000000 %
DpGetLoadAverage: la5[4] = 0.000000 / -1.000000 %
DpGetLoadAverage: la15[4] = 0.000000 / -1.000000 %
|  BTC |   0.000 |   0.000 |   0.000 |
+------+---------+---------+---------+
DpGetLoadAverage: la1[5] = 0.000000 / -1.000000 %
DpGetLoadAverage: la5[5] = 0.000000 / -1.000000 %
DpGetLoadAverage: la15[5] = 0.000000 / -1.000000 %
|  SPO |   0.000 |   0.000 |   0.000 |
+------+---------+---------+---------+
DpGetLoadAverage: la1[6] = 0.000000 / -1.000000 %
DpGetLoadAverage: la5[6] = 0.000000 / -1.000000 %
DpGetLoadAverage: la15[6] = 0.000000 / -1.000000 %
|  UP2 |   0.000 |   0.000 |   0.000 |
+------+---------+---------+---------+
Dump of tm_adm structure: Fri May 16 07:24:30 2014
=========================


Term    uid  man user    term   lastop  mod wp  ta   a/i (modes)
RM-T19, U20,                 , , 01:23:40, M0, W-1,     , 1/0


Workprocess Comm. Area Blocks Fri May 16 07:24:30 2014
=============================


Slots: 1000, Used: 2, Max: 46
+------+--------------+----------+-------------+
|   id | owner        |   pid    | eyecatcher  |
+------+--------------+----------+-------------+
|    0 | DISPATCHER   |       -1 | 0xdeadbeef |
|  546 | DISPATCHER   |       -1 | 0xdeadbeef |


NiWait: sleep (5000ms) ...
NiISelect: timeout 5000ms
NiISelect: maximum fd=1445
NiISelect: read-mask is NULL
NiISelect: write-mask is NULL
Fri May 16 01:24:35 2014
NiISelect: TIMEOUT occured (5000ms)
DpHalt: shutdown server >SAPERP_PRD_00                           < (normal)
DpJ2eeDisableRestart
DpMBufRead: read server list from MBUF (1 entries)
DpMBufMod: name [SAPERP_PRD_00                           ], types 191 state 3 (0x0 0x0 0x0 0x0)
DpMBufMod: call hooks for event MBUF_DPEVT_DSTATE (5->3)
AdGetSelfIdentRecord: >                                                                           <
AdCvtRecToExt: opcode 60 (AD_SELFIDENT), ser 0, ex 0, errno 0
AdCallRegisteredCvtToExt: opcode 60
AdCallRegisteredCvtToExt: opcode 60 call 000007F7B2B8B6E0
AdCallRegisteredCvtToExt: opcode 60 exit rc=SAP_O_K
AdCvtRecToExt: opcode 40 (AD_MSBUF), ser 0, ex 0, errno 0
AdCallRegisteredCvtToExt: opcode 40
AdCallRegisteredCvtToExt: opcode 40 call 000007F7B3297650
AdCallRegisteredCvtToExt: opcode 40 exit rc=SAP_O_K
AdCvtRecToExt: opcode 40 (AD_MSBUF), ser 0, ex 0, errno 0
AdCallRegisteredCvtToExt: opcode 40
AdCallRegisteredCvtToExt: opcode 40 call 000007F7B3297650
AdCallRegisteredCvtToExt: opcode 40 exit rc=SAP_O_K
AdCvtRecToExt: opcode 40 (AD_MSBUF), ser 0, ex 0, errno 0
AdCallRegisteredCvtToExt: opcode 40
AdCallRegisteredCvtToExt: opcode 40 call 000007F7B3297650
AdCallRegisteredCvtToExt: opcode 40 exit rc=SAP_O_K
AdCvtRecToExt: opcode 40 (AD_MSBUF), ser 0, ex 0, errno 0
AdCallRegisteredCvtToExt: opcode 40
AdCallRegisteredCvtToExt: opcode 40 call 000007F7B3297650
AdCallRegisteredCvtToExt: opcode 40 exit rc=SAP_O_K
AdCvtRecToExt: opcode 40 (AD_MSBUF), ser 0, ex 0, errno 0
AdCallRegisteredCvtToExt: opcode 40
AdCallRegisteredCvtToExt: opcode 40 call 000007F7B3297650
AdCallRegisteredCvtToExt: opcode 40 exit rc=SAP_O_K
AdCvtRecToExt: opcode 40 (AD_MSBUF), ser 0, ex 0, errno 0
AdCallRegisteredCvtToExt: opcode 40
AdCallRegisteredCvtToExt: opcode 40 call 000007F7B3297650
AdCallRegisteredCvtToExt: opcode 40 exit rc=SAP_O_K
AdCvtRecToExt: opcode 40 (AD_MSBUF), ser 0, ex 0, errno 0
AdCallRegisteredCvtToExt: opcode 40
AdCallRegisteredCvtToExt: opcode 40 call 000007F7B3297650
AdCallRegisteredCvtToExt: opcode 40 exit rc=SAP_O_K
AdCvtRecToExt: opcode 40 (AD_MSBUF), ser 0, ex 0, errno 0
AdCallRegisteredCvtToExt: opcode 40
AdCallRegisteredCvtToExt: opcode 40 call 000007F7B3297650
AdCallRegisteredCvtToExt: opcode 40 exit rc=SAP_O_K
AdCvtRecToExt: opcode 40 (AD_MSBUF), ser 0, ex 0, errno 0
AdCallRegisteredCvtToExt: opcode 40
AdCallRegisteredCvtToExt: opcode 40 call 000007F7B3297650
AdCallRegisteredCvtToExt: opcode 40 exit rc=SAP_O_K
AdCvtRecToExt: opcode 40 (AD_MSBUF), ser 0, ex 0, errno 0
AdCallRegisteredCvtToExt: opcode 40
AdCallRegisteredCvtToExt: opcode 40 call 000007F7B3297650
AdCallRegisteredCvtToExt: opcode 40 exit rc=SAP_O_K
DpWpBlksLow: wp_blks_in_queue/limit/max = 2/800/1000
DpLockWpBlkEx: lock wp ca_blk 1
make DISP owner of wp_ca_blk 1
DpRqIPutIntoQ: put elem in queue DIA, elems=6
DpRqPutIntoQueue: put request into queue (reqtype 1, prio LOW, rq_id 41)
MBUF server state SHUTDOWN
DpModState: change state STARTING -> SHUTDOWN


NiBufSend starting
NiIWrite: hdl 17 sent data (wrt=110,pac=1,MESG_IO)
MsINiWrite: sent 110 bytes
MsIModState: change state to SHUTDOWN
DpModState: change server state from STARTING to SHUTDOWN
DpHalt: switch off Shared memory profiling
ShmProtect( 57, 3 )
ShmProtect(SHM_PROFILE, SHM_PROT_RW
ShmProtect( 57, 1 )
ShmProtect(SHM_PROFILE, SHM_PROT_RD
DpWakeUpWps: wake up all wp's
DpHalt: stop work processes
DpHalt: stop gateway
killing process (7752) (SOFT_KILL)
DpHalt: stop icman
killing process (5940) (SOFT_KILL)
DpHalt: terminate gui connections
send SHUTDOWN to REM TM 19
DpWpBlksLow: wp_blks_in_queue/limit/max = 3/800/1000
DpLockWpBlkEx: lock wp ca_blk 2
return errno (-17) to T19
DpTmSend: errormsg without overhead: use mode 0
NiBufIAlloc: malloc NiBufadm, to 0 bytes
DpTmSend: try to send 14 bytes to T19/M0


NiBufSend starting
NiIWrite: hdl 25 sent data (wrt=14,pac=1,MESG_IO)
REL WP ca_blk 2
set status of T19 to TM_DISCONNECTED
NiBufISelUpdate: new MODE -- (r-) for hdl 25 in set0
SiSelNSet: set events of sock 1440 to: ---
NiBufISelRemove: remove hdl 25 from set0
SiSelNRemove: removed sock 1440 (pos=3)
SiSelNRemove: removed sock 1440
NiSelIRemove: removed hdl 25
DpDelSocketInfo: del info for nihdl 25 (pos/type=3/3)
NiICloseHandle: shutdown and close hdl 25/sock 1440
NiBufIClose: clear extension for hdl 25
dp_tm_adm[19].stat = DP_SLOT_FREE
DpGetSchedule: next schedule 1400225080/234000
DpGetSchedule: no schedule found
DpITmSlotRelease: release slot 19
DpListRemove: remove elem 19 from tmadm_inuse_list
DpListRemove: 19 elems in tmadm_inuse_list
DpListInsert: insert elem 19 into tmadm_free_list (at begin)
DpListInsert: 182 elems in tmadm_free_list
DpHalt: wait for end of work processes
DpHalt: wait for end of gateway
[DpProcDied] Process lives  (PID:7752  HANDLE:1300)
DpHalt: waiting for termination of gateway ...
NiWait: sleep (1000ms) ...
NiISelect: timeout 1000ms
NiISelect: maximum fd=1445
NiISelect: read-mask is NULL
NiISelect: write-mask is NULL
Fri May 16 01:24:36 2014
NiISelect: TIMEOUT occured (1000ms)
*** ERROR => [DpProcDied] Process died  (PID:7752  HANDLE:1300  rc:0x0) [dpnttool2.c  147]
DpHalt: wait for end of icman
[DpProcDied] Process lives  (PID:5940  HANDLE:1296)
DpHalt: waiting for termination of icman ...
NiWait: sleep (1000ms) ...
NiISelect: timeout 1000ms
NiISelect: maximum fd=1445
NiISelect: read-mask is NULL
NiISelect: write-mask is NULL
Fri May 16 01:24:37 2014
NiISelect: TIMEOUT occured (1000ms)
[DpProcDied] Process lives  (PID:5940  HANDLE:1296)
DpHalt: waiting for termination of icman ...
NiWait: sleep (1000ms) ...
NiISelect: timeout 1000ms
NiISelect: maximum fd=1445
NiISelect: read-mask is NULL
NiISelect: write-mask is NULL
Fri May 16 01:24:38 2014
NiISelect: TIMEOUT occured (1000ms)
[DpProcDied] Process lives  (PID:5940  HANDLE:1296)
DpHalt: waiting for termination of icman ...
NiWait: sleep (1000ms) ...
NiISelect: timeout 1000ms
NiISelect: maximum fd=1445
NiISelect: read-mask is NULL
NiISelect: write-mask is NULL
Fri May 16 01:24:39 2014
NiISelect: TIMEOUT occured (1000ms)
[DpProcDied] Process lives  (PID:5940  HANDLE:1296)
DpHalt: waiting for termination of icman ...
NiWait: sleep (1000ms) ...
NiISelect: timeout 1000ms
NiISelect: maximum fd=1445
NiISelect: read-mask is NULL
NiISelect: write-mask is NULL
Fri May 16 01:24:40 2014
NiISelect: TIMEOUT occured (1000ms)
[DpProcDied] Process lives  (PID:5940  HANDLE:1296)
DpHalt: waiting for termination of icman ...
NiWait: sleep (1000ms) ...
NiISelect: timeout 1000ms
NiISelect: maximum fd=1445
NiISelect: read-mask is NULL
NiISelect: write-mask is NULL
Fri May 16 01:24:41 2014
NiISelect: TIMEOUT occured (1000ms)
[DpProcDied] Process lives  (PID:5940  HANDLE:1296)
DpHalt: waiting for termination of icman ...
NiWait: sleep (1000ms) ...
NiISelect: timeout 1000ms
NiISelect: maximum fd=1445
NiISelect: read-mask is NULL
NiISelect: write-mask is NULL
Fri May 16 01:24:42 2014
NiISelect: TIMEOUT occured (1000ms)
[DpProcDied] Process lives  (PID:5940  HANDLE:1296)
DpHalt: waiting for termination of icman ...
NiWait: sleep (1000ms) ...
NiISelect: timeout 1000ms
NiISelect: maximum fd=1445
NiISelect: read-mask is NULL
NiISelect: write-mask is NULL
Fri May 16 01:24:43 2014
NiISelect: TIMEOUT occured (1000ms)
[DpProcDied] Process lives  (PID:5940  HANDLE:1296)
DpHalt: waiting for termination of icman ...
NiWait: sleep (1000ms) ...
NiISelect: timeout 1000ms
NiISelect: maximum fd=1445
NiISelect: read-mask is NULL
NiISelect: write-mask is NULL
Fri May 16 01:24:44 2014
NiISelect: TIMEOUT occured (1000ms)
*** ERROR => [DpProcDied] Process died  (PID:5940  HANDLE:1296  rc:0x0) [dpnttool2.c  147]
DpStartStopMsg: send stop message (myname is >SAPERP_PRD_00                           <)
DpStartStopMsg: Write AD_STARTSTOP message with type=  0, name=SAPERP_PRD_00       , sapsysnr= 0, hostname=SAPERP                                                         
AdGetSelfIdentRecord: >                                                                           <
AdCvtRecToExt: opcode 60 (AD_SELFIDENT), ser 0, ex 0, errno 0
AdCallRegisteredCvtToExt: opcode 60
AdCallRegisteredCvtToExt: opcode 60 call 000007F7B2B8B6E0
AdCallRegisteredCvtToExt: opcode 60 exit rc=SAP_O_K
AdCvtRecToExt: opcode 4 (AD_STARTSTOP), ser 0, ex 0, errno 0
AdCallRegisteredCvtToExt: opcode 4
AdCallRegisteredCvtToExt: opcode 4 call 000007F7B2BB1470
AdCallRegisteredCvtToExt: opcode 4 exit rc=SAP_O_K
DpConvertRequest: net size = 189 bytes
NiBufIAlloc: malloc MSLIB-BUF, to 32110 bytes


NiBufSend starting
NiIWrite: hdl 17 sent data (wrt=562,pac=1,MESG_IO)
MsINiWrite: sent 562 bytes
MsISnd2: send msg (ms hdr/msg 110/452 bytes) to name                    -, type 4, key -
DpStartStopMsg: stop msg sent
NiBufIAlloc: malloc MSLIB-BUF, to 32110 bytes
NiBufIAlloc: malloc NIBUF-IN, to 32110 bytes
NiIRead: hdl 17 received data (rcd=274,pac=1,MESG_IO)
NiBufIIn: NIBUF len=274
NiBufIIn: packet complete for hdl 17


NiBufReceive starting
MsINiRead: received 274 bytes
MsIReceive: received msg (ms hdr/msg 110/164 bytes), flag 1, from MSG_SERVER          , typ 0, key -
DpHalt: received 164 bytes from message server
NiIRead: hdl 17 recv would block (errno=EAGAIN)
NiIRead: read for hdl 17 timed out (0ms)
DpHalt: more messages from the message server
DpHalt: send keepalive to synchronize with the message server


NiBufSend starting
NiIWrite: hdl 17 sent data (wrt=114,pac=1,MESG_IO)
MsINiWrite: sent 114 bytes
MsISnd2: send msg (ms hdr/msg 110/4 bytes) to name           MSG_SERVER, type 0, key -
MsSndName: MS_NOOP ok
Send 4 bytes to MSG_SERVER
NiBufIAlloc: malloc MSLIB-BUF, to 32110 bytes
NiIRead: hdl 17 recv would block (errno=EAGAIN)
NiIPeek: peek successful for hdl 17 (r)
NiBufIAlloc: malloc NIBUF-IN, to 32110 bytes
NiIRead: hdl 17 received data (rcd=114,pac=1,MESG_IO)
NiBufIIn: NIBUF len=114
NiBufIIn: packet complete for hdl 17


NiBufReceive starting
MsINiRead: received 114 bytes
MsIReceive: received msg (ms hdr/msg 110/4 bytes), flag 3, from MSG_SERVER          , typ 0, key -
Received 4 bytes from MSG_SERVER                             
Received opcode MS_NOOP from msg_server, reply MSOP_OK
MsOpReceive: ok
MsISendKeepalive : keepalive sent to message server
NiIRead: hdl 17 recv would block (errno=EAGAIN)
Fri May 16 01:24:45 2014
NiIPeek: peek for hdl 17 timed out (r; 1000ms)
NiIRead: read for hdl 17 timed out (1000ms)
DpHalt: no more messages from the message server
DpHalt: sync with message server o.k.
DpHalt: detach from message server
***LOG Q0M=> DpMsDetach, ms_detach () [dpxxdisp.c   13064]


NiBufSend starting
NiIWrite: hdl 17 sent data (wrt=110,pac=1,MESG_IO)
MsINiWrite: sent 110 bytes
MsIDetach: send logout to msg_server (SAPERP / 3900)
MsIDetach: call exit function
DpMsShutdownHook called
NiBufISelUpdate: new MODE -- (r-) for hdl 17 in set0
SiSelNSet: set events of sock 1400 to: ---
NiBufISelRemove: remove hdl 17 from set0
SiSelNRemove: removed sock 1400 (pos=2)
SiSelNRemove: removed sock 1400
NiSelIRemove: removed hdl 17
DpDelSocketInfo: del info for nihdl 17 (pos/type=2/4)
MBUF state OFF
AdGetSelfIdentRecord: >                                                                           <
AdCvtRecToExt: opcode 60 (AD_SELFIDENT), ser 0, ex 0, errno 0
AdCallRegisteredCvtToExt: opcode 60
AdCallRegisteredCvtToExt: opcode 60 call 000007F7B2B8B6E0
AdCallRegisteredCvtToExt: opcode 60 exit rc=SAP_O_K
AdCvtRecToExt: opcode 40 (AD_MSBUF), ser 0, ex 0, errno 0
AdCallRegisteredCvtToExt: opcode 40
AdCallRegisteredCvtToExt: opcode 40 call 000007F7B3297650
AdCallRegisteredCvtToExt: opcode 40 exit rc=SAP_O_K
AdCvtRecToExt: opcode 40 (AD_MSBUF), ser 0, ex 0, errno 0
AdCallRegisteredCvtToExt: opcode 40
AdCallRegisteredCvtToExt: opcode 40 call 000007F7B3297650
AdCallRegisteredCvtToExt: opcode 40 exit rc=SAP_O_K
DpWpBlksLow: wp_blks_in_queue/limit/max = 3/800/1000
DpLockWpBlkEx: lock wp ca_blk 2
make DISP owner of wp_ca_blk 2
DpRqIPutIntoQ: put elem in queue DIA, elems=7
DpRqPutIntoQueue: put request into queue (reqtype 1, prio LOW, rq_id 44)
MBUF component DOWN
NiICloseHandle: shutdown and close hdl 17/sock 1400
NiBufIClose: clear extension for hdl 17
MsIDetach: detach MS-system (SAPERP / 3900)
DpHalt: cleanup EM
EsCleanup( )
EsCleanup ....
EmCleanup() -> 0
Es2Cleanup: Cleanup ES2
***LOG Q05=> DpHalt, DPStop ( 4924) [dpxxdisp.c   11574]
DpHalt: Good Bye .....

SAPSTARTSRV

---------------------------------------------------
trc file: "sapstartsrv.log", trc level: 0, release: "721"
---------------------------------------------------
pid        6196


[Thr 6528] Fri May 16 00:38:09 2014
SAP HA Trace: SAP Microsoft Cluster library '721, patch 100, changelist 1397439' initialized
CCMS agent initialization for instance type ABAP: return code 0.
CCMS agent start: return code 0.
Initializing SAPControl Webservice
Starting AutoRestart thread
AutoRestart thread started, version check is enabled
SapSSLInit failed => https support disabled
Starting WebService Named Pipe thread
Starting WebService thread
Webservice named pipe thread started, listening on port \\.\pipe\sapcontrol_00
Webservice thread started, listening on port 50013


\sapadmin is starting SAP System at 2014/05/16  0:38:18
SAP HA Trace: FindClusterResource: OpenCluster failed: 1753 [sapwinha.cpp, line 213]
SAP HA Trace: SAP_HA_FindSAPInstance returns: SAP_HA_FAIL [sapwinha.cpp, line 920]
\sapadmin is stopping SAP System at 2014/05/16  0:49:10
SAP HA Trace: FindClusterResource: OpenCluster failed: 1753 [sapwinha.cpp, line 213]
SAP HA Trace: SAP_HA_FindSAPInstance returns: SAP_HA_FAIL [sapwinha.cpp, line 920]


\sapadmin is starting SAP System at 2014/05/16  0:50:47
SAP HA Trace: FindClusterResource: OpenCluster failed: 1753 [sapwinha.cpp, line 213]
SAP HA Trace: SAP_HA_FindSAPInstance returns: SAP_HA_FAIL [sapwinha.cpp, line 920]
\sapadmin is stopping SAP System at 2014/05/16  1:21:22
SAP HA Trace: FindClusterResource: OpenCluster failed: 1753 [sapwinha.cpp, line 213]
SAP HA Trace: SAP_HA_FindSAPInstance returns: SAP_HA_FAIL [sapwinha.cpp, line 920]


\prdadm is starting SAP System at 2014/05/16  1:23:04
SAP HA Trace: FindClusterResource: OpenCluster failed: 1753 [sapwinha.cpp, line 213]
SAP HA Trace: SAP_HA_FindSAPInstance returns: SAP_HA_FAIL [sapwinha.cpp, line 920]

[Former Member · Accepted solution]

Please check/attach dev_icm log file. Check also if SAP KBA 1934023 - Application server startup fail with an ICM connection error is relevant to your issue.

[Former Member · Accepted solution]

Hi Roman,

Following that note appears to have fixed my issue. I do not know why the port was being blocked or having issues communicating, but specifying icm/admin_port to 70000 and starting has allowed me to start my server.

Thank you very much.

[Former Member]

Hi Steve,

Looks like you did not mention the parameter you have changed.

If it is a SAP parameter, you can check once with sappfpar check=<instance param.>, if that brings up any error.

The other thing is, please follow the SAP note Roman advised, and , bounce the windows server as Reagan has advised, if you believe an issue with shared memory; and if it does not work, we would like to see dev_icm and dev_disp trace files to check more.

Again, it looks ICM has some issues.

DpMsgProcess: 1 server in MBUF

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

*** ERROR => DpIcmMsgProcess: IcmRecMsg (rc=-8,-6) [dpxxdisp.c   19121]

Also, I would request you to check the below warning if there is any issue with DNS/network.

Fri May 16 01:23:12 2014

*** WARNING => DpNetCheck: NiAddrToHost(1.0.0.0) took 4 seconds

***LOG GZZ=> 1 possible network problems detected - check tracefile and adjust the DNS settings [dpxxtool2.c  6438]

MtxInit: 30000 0 0

Let us know if this helps.

Regards,

Sujit Kumar Banerjee.

[Former Member]

Hi Sujit,

The only parameter changes I performed were adding:

login/create_sso2_ticket = 2

login/accept_sso2_ticket = 1

I moved to older instance profiles and my errors persisted, I do not believe this is related to profiles.

I performed sappfpar check operations but did not see any errors, only warnings for potentially unknown parameters.

Do you know what this ICM error implies?

Sujit Kumar Banerjee wrote:


Again, it looks ICM has some issues.

DpMsgProcess: 1 server in MBUF
DpAppcBlksLow: max appc blocks in queue is 500 (50 %)
*** ERROR => DpIcmMsgProcess: IcmRecMsg (rc=-8,-6) [dpxxdisp.c   19121]'

[alwina_enns]

I agree with Roman,

ICM cannot start, most likely its port is used. Please check dev_icm to which port ICM is listening and check with netstat on OS level, if this port is in use.

[Former Member]

Hi Alwina, here is the DEV_ICM trace:

From this trace, it appears that it is listening to 65000?

Netstat shows that the system is listening to 127.0.0.1:65000 .

Other SAP ports show listening on 0:0:0:0:xxxx , is ICM listening on 127 a problem?

---------------------------------------------------
trc file: "dev_icm", trc level: 1, release: "721"
---------------------------------------------------
sysno      00
sid        PRD
systemid   562 (PC with Windows NT)
relno      7210
patchlevel 0
patchno    43
intno      20020600
make       multithreaded, Unicode, 64 bit, optimized
profile    \\SAPERP\sapmnt\PRD\SYS\profile\PRD_DVEBMGS00_SAPERP
pid        5940




[Thr 1812] Fri May 16 01:23:13 2014
[Thr 1812] Parameter system/type has value: "ABAP"
[Thr 1812] started security log to file ./dev_icm_sec
[Thr 1812] ICM running on:
[Thr 1812] MtxInit: 30001 0 2
[Thr 1812] ***LOG IM1=> IcmInit, Startup (ICM&SAPERP.CORP.CANSEL.CA&5940&) [icxxman.c    1934]
[Thr 1812] IcmInit: listening to admin port: 65000
[Thr 1812] DpSysAdmExtCreate: ABAP is active
[Thr 1812] DpSysAdmExtCreate: VMC (JAVA VM in WP) is not active
[Thr 1812] DpIPCInit2: read dp-profile-values from sys_adm_ext
[Thr 1812] DpShMCreate: sizeof(wp_adm) 42864 (2256)
[Thr 1812] DpShMCreate: sizeof(tm_adm) 5517056 (27448)
[Thr 1812] DpShMCreate: sizeof(wp_ca_adm) 64000 (64)
[Thr 1812] DpShMCreate: sizeof(appc_ca_adm) 64000 (64)
[Thr 1812] DpCommTableSize: max/headSize/ftSize/tableSize=500/16/1384064/1384080
[Thr 1812] DpShMCreate: sizeof(comm_adm) 1384080 (2744)
[Thr 1812] DpSlockTableSize: max/headSize/ftSize/fiSize/tableSize=0/0/0/0/0
[Thr 1812] DpShMCreate: sizeof(slock_adm) 0 (296)
[Thr 1812] DpFileTableSize: max/headSize/ftSize/tableSize=0/0/0/0
[Thr 1812] DpShMCreate: sizeof(file_adm) 0 (80)
[Thr 1812] DpShMCreate: sizeof(vmc_adm) 0 (2160)
[Thr 1812] DpShMCreate: sizeof(wall_adm) (41664/42896/64/192)
[Thr 1812] DpShMCreate: sizeof(gw_adm) 48
[Thr 1812] DpShMCreate: sizeof(j2ee_adm) 3952
[Thr 1812] DpShMCreate: SHM_DP_ADM_KEY (addr: 00000000022F0050, size: 7174832)
[Thr 1812] DpShMCreate: allocated sys_adm at 00000000022F0060
[Thr 1812] DpShMCreate: allocated wp_adm_list at 00000000022F30B0
[Thr 1812] DpShMCreate: allocated wp_adm at 00000000022F32A0
[Thr 1812] DpShMCreate: allocated tm_adm_list at 00000000022FDA20
[Thr 1812] DpShMCreate: allocated tm_adm at 00000000022FDA70
[Thr 1812] DpShMCreate: allocated wp_ca_adm at 0000000002840980
[Thr 1812] DpShMCreate: allocated appc_ca_adm at 0000000002850390
[Thr 1812] DpShMCreate: allocated comm_adm at 000000000285FDA0
[Thr 1812] DpShMCreate: system runs without slock table
[Thr 1812] DpShMCreate: system runs without file table
[Thr 1812] DpShMCreate: allocated vmc_adm_list at 00000000029B1C40
[Thr 1812] DpShMCreate: system runs without vmc_adm
[Thr 1812] DpShMCreate: allocated gw_adm at 00000000029B1CF0
[Thr 1812] DpShMCreate: allocated j2ee_adm at 00000000029B1D30
[Thr 1812] DpShMCreate: allocated ca_info at 00000000029B2CB0
[Thr 1812] DpRqQInit: use protect_queue / slots_per_queue 0 / 2001 from sys_adm
[Thr 1812] MPI: dynamic quotas disabled.
[Thr 1812] MPI init: pipes=4000 buffers=1279 reserved=383 quota=10%
[Thr 1812] CCMS: initialize CCMS Monitoring for ABAP instance with J2EE addin.
[Thr 1812] CCMS: SemInMgt: Semaphore Management initialized by AlAttachShm_Doublestack.


[Thr 1812] Fri May 16 01:23:14 2014
[Thr 1812] CCMS: SemInit: Semaphore 38 initialized by AlAttachShm_Doublestack.
[Thr 1812] IcmCreateWorkerThreads: created worker thread 0
[Thr 1812] IcmCreateWorkerThreads: created worker thread 1
[Thr 1812] IcmCreateWorkerThreads: created worker thread 2
[Thr 6912] IcmProxyWatchDog: proxy watchdog started
[Thr 1812] IcmCreateWorkerThreads: created worker thread 3
[Thr 1812] IcmCreateWorkerThreads: created worker thread 4
[Thr 1812] IcmCreateWorkerThreads: created worker thread 5
[Thr 1812] IcmCreateWorkerThreads: created worker thread 6
[Thr 1812] IcmCreateWorkerThreads: created worker thread 7
[Thr 1812] IcmCreateWorkerThreads: created worker thread 8
[Thr 1812] IcmCreateWorkerThreads: created worker thread 9
[Thr 4024] IcmMpiWatchDogThread: MPI watchdog started
[Thr 4400] IcmWatchDogThread: watchdog started
[Thr 6524] HttpISubHandlerAdd: Added handler HttpFileAccessHandler(000000000C2E2750), slot=0, flags=4098) for /sap/public/icmandir/, active: 1, table 000000000C2E24C0
[Thr 6524] ISC: created 400 MB disk cache.
[Thr 6524] ISC: created 50 MB memory cache.
[Thr 6524] HttpISubHandlerAdd: Added handler HttpCacheHandler(000000000C3EB4B0), slot=1, flags=12293) for /, active: 1, table 000000000C2E24C0
[Thr 6524] HttpExtractArchive: files from archive E:\usr\sap\PRD\DVEBMGS00\exe/icmadmin.SAR in directory E:/usr/sap/PRD/DVEBMGS00/data/icmandir are up to date
[Thr 6524] HttpISubHandlerAdd: Added handler HttpAdminHandler(000000000C461480), slot=2, flags=36869) for /sap/admin, active: 1, table 000000000C2E24C0
[Thr 6524] HttpISubHandlerAdd: Added handler HttpModHandler(000000000C461570), slot=3, flags=12293) for /, active: 1, table 000000000C2E24C0
[Thr 6524] CsiInit(): Initializing the Content Scan Interface
[Thr 6524]            PC with Windows NT (mt,unicode,SAP_CHAR/size_t/void* = 16/64/64)
[Thr 6524] CsiInit(): CSA_LIB = "E:\usr\sap\PRD\DVEBMGS00\exe\sapcsa.dll"
[Thr 6524] HttpISubHandlerAdd: Added handler HttpAuthHandler(000000000C4615F0), slot=4, flags=12293) for /, active: 1, table 000000000C2E24C0
[Thr 6524] HttpISubHandlerAdd: Added handler HttpSAPR3Handler(000000000C4AFAE0), slot=5, flags=1052677) for /, active: 1, table 000000000C2E24C0
[Thr 6524] Started service PORT=8000,PROT=HTTP,TIMEOUT=60,PROCTIMEOUT=60
[Thr 6524] Started service PORT=0,PROT=SMTP,TIMEOUT=120,PROCTIMEOUT=120


[Thr 6524] Fri May 16 01:23:18 2014
[Thr 6524] IcmNetCheck: network check passed without detecting problems


[Thr 4268] Fri May 16 01:23:24 2014
[Thr 4268] HttpExtractArchive: files from archive E:\usr\sap\PRD\DVEBMGS00\exe/ITS.SAR in directory E:/usr/sap/PRD/DVEBMGS00/data/icmandir are up to date


[Thr 8156] Fri May 16 01:24:14 2014
[Thr 8156] *** WARNING => IcmCallAllSchedules: Schedule func 1 already running - avoid recursion [icxxsched.c  481]


[Thr 5948] Fri May 16 01:24:24 2014
[Thr 5948] *** WARNING => IcmJ2EEScheduleFunc: Cannot access "/sap/public/icman" (rc=500)- please check node in TA sicf [icxxman.c    2598]


[Thr 6912] Fri May 16 01:24:44 2014
[Thr 6912] IcmProxyWatchDog: Shutdown request received
[Thr 4400] IcmWatchDogThread: Shutdown request received
[Thr 6912] *** IcmProxyWatchDog: exit thread ***
[Thr 4024] *** IcmMpiWatchDogThread: exit thread ***
[Thr 4400] *** IcmWatchDogThread: exit thread ***
[Thr 1812] IcmLoop: Shutdown request received
[Thr 1812] Deactivated service PORT=8000,PROT=HTTP,TIMEOUT=60,PROCTIMEOUT=60
[Thr 1812] Deactivated service PORT=0,PROT=SMTP,TIMEOUT=120,PROCTIMEOUT=120
[Thr 1812] Removed service PORT=8000,PROT=HTTP,TIMEOUT=60,PROCTIMEOUT=60
[Thr 1812] Removed service PORT=0,PROT=SMTP,TIMEOUT=120,PROCTIMEOUT=120
[Thr 1812] *** ICM shutdown completed (pid: 5940) ***

[alwina_enns]

Hello Steve,

127.0.0.1 is the ip address of the local machine, all entries with 127.0.0.1 are OK. I'm not sure what should be the entries with 0:0:0:0:xxxx. With "netstat -ao | findstr 65000" you can find out the PID of the process, using the port 65000, and you can check in taskmanager, which process has this PID. You have mentioned, that some web dispatchers are running on the server, most likely one of them is using the port 65000.

[Reagan]

Have you tried restarting the Windows ?

I would try that.

[Former Member]

Hi Reagan,

I did restart the windows server, and had the same error when it came back up.