ABAP processes of instance XXX/DVEBMGS04 [ABAP: STARTING] did not start after 10:10 minutes. Giving up

[ibrahim_yooseff]

I am getting this error while installing SAP SM 7.1 

An error occurred while processing option SAP Solution Manager 7.1 support release 1 > SAP System> SAP ASE > Central System> central System

(Last error reported by the step: ABAP processes of instance SM8/DVEBMGS04 { ABAP: STARTING} did not start after 10:10 minutes giving up) 

help needed..kindly go through the attached files 

[ibrahim_yooseff]

hello all , Dev_disp --------------------------------------------------- trc file: "dev_disp", trc level: 1, release: "721" --------------------------------------------------- sysno      04 sid        SM8 systemid  562 (PC with Windows NT) relno      7210 patchlevel 0 patchno    402 intno      20020600 make      multithreaded, Unicode, 64 bit, optimized profile    \\ibis\sapmnt\SM8\SYS\profile\SM8_DVEBMGS04_ibis pid        4348 kernel runs with dp version 139000(ext=121000) (@(#) DPLIB-INT-VERSION-139000-UC) length of sys_adm_ext is 592 bytes *** SWITCH TRC-HIDE on *** ***LOG Q00=> DpSapEnvInit, DPStart (04 4348) [dpxxdisp.c  1323] shared lib "dw_xml.dll" version 402 successfully loaded shared lib "dw_xtc.dll" version 402 successfully loaded shared lib "dw_stl.dll" version 402 successfully loaded shared lib "dw_gui.dll" version 402 successfully loaded shared lib "dw_mdm.dll" version 402 successfully loaded shared lib "dw_rndrt.dll" version 402 successfully loaded shared lib "dw_abp.dll" version 402 successfully loaded shared lib "dw_sym.dll" version 402 successfully loaded shared lib "dw_aci.dll" version 402 successfully loaded rdisp/softcancel_sequence :  -> 0,5,-1 use internal message server connection to port 3905 rdisp/dynamic_wp_check : 1 rdisp/calculateLoadAverage : 1 Tue Apr 21 08:52:14 2015 *** WARNING => DpNetCheck: NiAddrToHost(1.0.0.0) took 5 seconds ***LOG GZZ=> 1 possible network problems detected - check tracefile and adjust the DNS settings [dpxxtool2.c  6525] MtxInit: 30000 0 0 DpSysAdmExtInit: ABAP is active DpSysAdmExtInit: VMC (JAVA VM in WP) is not active display_tcp_ip: 0 Set Check Logoff Flags to 0x0 DpIPCInit2: write dp-profile-values into sys_adm_ext DpIPCInit2: start server >ibis_SM8_04                            < DpShMCreate: sizeof(wp_adm) 40608 (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/1392064/1392080 DpShMCreate: sizeof(comm_adm) 1392080 (2768) 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: 0000000003190050, size: 7180576) DpShMCreate: allocated sys_adm at 0000000003190060 DpShMCreate: allocated wp_adm_list at 00000000031930B0 DpShMCreate: allocated wp_adm at 00000000031932A0 DpShMCreate: allocated tm_adm_list at 000000000319D150 DpShMCreate: allocated tm_adm at 000000000319D1A0 DpShMCreate: allocated wp_ca_adm at 00000000036E00B0 DpShMCreate: allocated appc_ca_adm at 00000000036EFAC0 DpShMCreate: allocated comm_adm at 00000000036FF4D0 DpShMCreate: system runs without slock table DpShMCreate: system runs without file table DpShMCreate: allocated vmc_adm_list at 00000000038532B0 DpShMCreate: system runs without vmc_adm DpShMCreate: allocated gw_adm at 0000000003853360 DpShMCreate: allocated j2ee_adm at 00000000038533A0 DpShMCreate: allocated ca_info at 0000000003854320 DpShMCreate: allocated wall_adm at 00000000038543B0 DpCommAttachTable: attached comm table (header=00000000036FF4D0/ft=00000000036FF4E0) 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 rdisp/queue_size_check_value :  -> on,50,30,40,500,50,500,80 EmInit: MmSetImplementation( 2 ). MM global diagnostic options set: 0 client 0 initializing .... EsILock: use Mutex for locking InitFreeList block size is 4096 kByte. Info: em/initial_size_MB( 16330MB) not multiple of em/blocksize_KB( 4096KB) Info: em/initial_size_MB rounded up to 16332MB Using implementation view Using memory model view. Memory Reset disabled as NT default 4082 blocks reserved for free list. ES initialized. mm.dump: set maximum dump mem to 192 MB mm.dump: set global maximum dump mem to 192 MB EsRegisterEmCheck: Register EmGetEsHandles at 00000001419AF6D0 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 ( 3.4 3.4 4.1) [dpxxdisp.c  1709] ***LOG Q0K=> DpMsAttach, mscon ( ibis) [dpxxdisp.c  12944] MBUF state LOADING DpStartStopMsg: send start message (myname is >ibis_SM8_04                            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 Apr 21 08:52:54 2015 *** ERROR => DpHdlDeadWp: W0 (pid 4656) died (severity=0, status=0) [dpxxwp.c    1746] *** ERROR => DpHdlDeadWp: W1 (pid 564) died (severity=0, status=0) [dpxxwp.c    1746] *** ERROR => DpHdlDeadWp: W2 (pid 3440) died (severity=0, status=0) [dpxxwp.c    1746] *** ERROR => DpHdlDeadWp: W3 (pid 4956) died (severity=0, status=0) [dpxxwp.c    1746] *** ERROR => DpHdlDeadWp: W4 (pid 4940) died (severity=0, status=0) [dpxxwp.c    1746] *** ERROR => DpHdlDeadWp: W6 (pid 3512) died (severity=0, status=0) [dpxxwp.c    1746] *** ERROR => DpHdlDeadWp: W7 (pid 3528) died (severity=0, status=0) [dpxxwp.c    1746] *** ERROR => DpHdlDeadWp: W8 (pid 4724) died (severity=0, status=0) [dpxxwp.c    1746] *** ERROR => DpHdlDeadWp: W9 (pid 4772) died (severity=0, status=0) [dpxxwp.c    1746] *** ERROR => DpHdlDeadWp: W10 (pid 780) died (severity=0, status=0) [dpxxwp.c    1746] *** ERROR => DpHdlDeadWp: W11 (pid 4768) died (severity=0, status=0) [dpxxwp.c    1746] *** ERROR => DpHdlDeadWp: W12 (pid 312) died (severity=0, status=0) [dpxxwp.c    1746] *** ERROR => DpHdlDeadWp: W13 (pid 164) died (severity=0, status=0) [dpxxwp.c    1746] *** ERROR => DpHdlDeadWp: W14 (pid 3536) died (severity=0, status=0) [dpxxwp.c    1746] *** ERROR => DpHdlDeadWp: W15 (pid 4204) died (severity=0, status=0) [dpxxwp.c    1746] Tue Apr 21 08:53:14 2015 ***LOG Q0J=> DpEnvCheck, no_wp () [dpxxdisp.c  8587] ***LOG Q0G=> DpRqBadHandle, bad_req ( UPD) [dpxxdisp.c  6264] *** ERROR => DpRqBadHandle: BAD REQUEST - Reason: senseless request (line 8589): [dpxxdisp.c  6266] -IN-- sender_id DISPATCHER        tid  -1    wp_ca_blk  826    wp_id 13 -IN-- action    SEND_TO_WP        uid  -1    appc_ca_blk -1      type  UPD  -IN-- new_stat  NO_CHANGE        mode 255  len        410    rq_id 34 -IN-- req_info  MSG_WITH_REQ_BUF,MSG_WITH_OH,SET_SYSTEM_USER -IN-- msg_name  ibis_SM8_04        Tue Apr 21 08:54:04 2015 DpSigInt: caught signal 2 DpHalt: shutdown server >ibis_SM8_04                            < (normal) DpModState: change server state from STARTING to SHUTDOWN DpHalt: stop work processes Tue Apr 21 08:55:05 2015 DpHalt: stop gateway DpHalt: stop icman DpHalt: terminate gui connections DpHalt: wait for end of work processes DpHalt: waiting for termination of work processes ... Tue Apr 21 08:55:06 2015 DpHalt: wait for end of gateway *** ERROR => [DpProcDied] Process died  (PID:160  HANDLE:976  rc:0x0) [dpnttool2.c  147] DpHalt: wait for end of icman DpHalt: waiting for termination of icman ... Tue Apr 21 08:55:07 2015 DpHalt: waiting for termination of icman ... Tue Apr 21 08:55:08 2015 DpHalt: waiting for termination of icman ... Tue Apr 21 08:55:09 2015 DpHalt: waiting for termination of icman ... Tue Apr 21 08:55:10 2015 DpHalt: waiting for termination of icman ... Tue Apr 21 08:55:11 2015 DpHalt: waiting for termination of icman ... Tue Apr 21 08:55:12 2015 DpHalt: waiting for termination of icman ... Tue Apr 21 08:55:13 2015 DpHalt: waiting for termination of icman ... Tue Apr 21 08:55:14 2015 DpHalt: waiting for termination of icman ... Tue Apr 21 08:55:15 2015 *** ERROR => [DpProcDied] Process died  (PID:1772  HANDLE:984  rc:0x0) [dpnttool2.c  147] DpStartStopMsg: send stop message (myname is >ibis_SM8_04                            DpMsDetach, ms_detach () [dpxxdisp.c  13344] MBUF state OFF MBUF component DOWN DpHalt: cleanup EM ***LOG Q05=> DpHalt, DPStop ( 4348) [dpxxdisp.c  11819]

[ibrahim_yooseff]

dev_w0

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

trc file: "dev_w0", trc level: 1, release: "721"

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

*

*  ACTIVE TRACE LEVEL           1

*  ACTIVE TRACE COMPONENTS      all, MJ

*

M sysno      04

M sid        SM8

M systemid   562 (PC with Windows NT)

M relno      7210

M patchlevel 0

M patchno    402

M intno      20020600

M make       multithreaded, Unicode, 64 bit, optimized

M profile    \\ibis\sapmnt\SM8\SYS\profile\SM8_DVEBMGS04_ibis

M pid        4656

M

M  kernel runs with dp version 139000(ext=121000) (@(#) DPLIB-INT-VERSION-139000-UC)

M  length of sys_adm_ext is 592 bytes

M  ***LOG Q0Q=> tskh_init, WPStart (Workp. 0 4656) [dpxxdisp.c   1385]

I  MtxInit: 30000 0 0

M  DpSysAdmExtCreate: ABAP is active

M  DpSysAdmExtCreate: VMC (JAVA VM in WP) is not active

M  DpSysAdmExtCreate: J2EE Engine running with this server

M 

M Tue Apr 21 08:52:15 2015

M  DpIPCInit2: read dp-profile-values from sys_adm_ext

M  DpShMCreate: sizeof(wp_adm) 40608 (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/1392064/1392080

M  DpShMCreate: sizeof(comm_adm) 1392080 (2768)

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: 000000000B540050, size: 7180576)

M  DpShMCreate: allocated sys_adm at 000000000B540060

M  DpShMCreate: allocated wp_adm_list at 000000000B5430B0

M  DpShMCreate: allocated wp_adm at 000000000B5432A0

M  DpShMCreate: allocated tm_adm_list at 000000000B54D150

M  DpShMCreate: allocated tm_adm at 000000000B54D1A0

M  DpShMCreate: allocated wp_ca_adm at 000000000BA900B0

M  DpShMCreate: allocated appc_ca_adm at 000000000BA9FAC0

M  DpShMCreate: allocated comm_adm at 000000000BAAF4D0

M  DpShMCreate: system runs without slock table

M  DpShMCreate: system runs without file table

M  DpShMCreate: allocated vmc_adm_list at 000000000BC032B0

M  DpShMCreate: system runs without vmc_adm

M  DpShMCreate: allocated gw_adm at 000000000BC03360

M  DpShMCreate: allocated j2ee_adm at 000000000BC033A0

M  DpShMCreate: allocated ca_info at 000000000BC04320

M  DpShMCreate: allocated wall_adm at 000000000BC043B0

M  DpCommAttachTable: attached comm table (header=000000000BAAF4D0/ft=000000000BAAF4E0)

M  DpRqQInit: use protect_queue / slots_per_queue 0 / 2001 from sys_adm

M 

M Tue Apr 21 08:52:16 2015

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 Mutex 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 192 MB

X  mm.dump: set global maximum dump mem to 192 MB

X  EsRegisterEmCheck: Register EmGetEsHandles at 00000001419AF6D0

M  DpVmcSetActive: set vmc state DP_VMC_NOT_ACTIVE

M  ThStart: taskhandler started

M  ThTHPInit: thp initialized

M  ThInit: initializing DIA work process W0

M 

M Tue Apr 21 08:52:19 2015

M  ThInit: running on host ibis

M 

M Tue Apr 21 08:52:20 2015

M  calling db_connect ...

B  Loading DB library 'E:\usr\sap\SM8\DVEBMGS04\exe\dbsybslib.dll' ...

B  Library 'E:\usr\sap\SM8\DVEBMGS04\exe\dbsybslib.dll' loaded

B  Version of 'E:\usr\sap\SM8\DVEBMGS04\exe\dbsybslib.dll' is "721.02", patchlevel (0.330)

C  trace file set

C  Callback functions for dynamic profile parameter registered

B  con_info_ext_support(): DBSL supports extended connect protocol

B    ==> connect info for default DB will be read from ssfs

C 

C Tue Apr 21 08:52:21 2015

C  database is local: connect_timeout: 3

C  Thread ID:4760

C  lib_dbsl 721 10/15/2014 10:18:00

C  connection unquiesced

C  721_EXT build

C  Using dynamic link library 'E:\usr\sap\SM8\DVEBMGS04\exe\dbsybslib.dll'

C  dbsybslib.dll patch info

C    SAP patchlevel  0

C    SAP patchno  401

C    Last SYBASE DBSL patchlevel 0

C    Last SYBASE DBSL patchno         330

C    Last SYBASE DBSL patchcomment SYB: SQL error 590 after restart of ASE (2065899)

C 

C Tue Apr 21 08:52:22 2015

C  spid 160 comm rd ODBC

C  spid 81 unc rd ODBC

C  Driver: Adaptive Server Enterprise Driver release: 15.7.0.1314

C  Driver full version: SAP ASE ODBC Driver/15.7/SP131 N-OFF/P/AMD64/Windows/drvmain/Build 1314/64-bit/Normal/Sat Jan 17 UTC 03:21:06 2015/SQLLEN8

C  Driver uses SQLLEN8

C  dbs/syb/cache_size: 300

C  GetServerInfo version: Adaptive Server Enterprise/15.7/EBF 23816 SMP SP132 /P/X64/Windows Server/ase157sp131x/3920/64-bit/OPT/Wed Jan 21 00:15:02 2015

C  GetServerInfo release: 15.7.0.132

C  GetServerInfo architecture: x86_64

C  GetServerInfo edition: P

C  GetServerInfo byte width: 64 bit

C  DbSlConnect hdl: 0

C  trace file set

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,*.jpg,*.pdf,*.gzip,*.uue,*.bz2,*.iso,*.sda,*.sar,*.gif,*.png,*.swc,*.swf

I 

I Tue Apr 21 08:52:25 2015

I  MtxInit: 0 0 0

M  SHM_PRES_BUF (addr: 0000000012360050, size: 4400000)

M  SHM_ROLL_AREA (addr: 00007FFFDDAB0050, size: 268435456)

M  SHM_PAGING_AREA (addr: 00000000127A0050, size: 134217728)

M  SHM_ROLL_ADM (addr: 000000001A7B0050, size: 2767448)

M  SHM_PAGING_ADM (addr: 000000001AA60050, size: 787488)

M  ThCreateNoBuffer allocated 548152 bytes for 1000 entries at 0000000002EE0050

M  ThCreateNoBuffer index size: 3000 elems

M  ThCreateVBAdm allocated 31056 bytes (50 server) at 0000000002F80050

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 192 MB

X  mm.dump: set global maximum dump mem to 192 MB

X  EsRegisterEmCheck: Register EmGetEsHandles at 00000001419AF6D0

B  db_con_shm_ini:  WP_ID = 0, WP_CNT = 18, CON_ID = -1

B  dbtbxbuf: Buffer TABL  (addr: 0000000033DE0160, size: 30000000, end: 0000000035A7C4E0)

B  dbtbxbuf: Buffer TABLP (addr: 0000000035A80160, size: 10240000, end: 0000000036444160)

B  dbsync[db_syinit]: successfully attached to shared memory, sync_adm_p = 0000000002F90050

B  dbsync[db_syinit]: Buffer synchronisation started with

B    sync_concept      = SEQ_NR

B    sendon            = 0

B    bufreftime        = 120

B    max_gap_wait_time = 60

B    ddlog_del_time    = 60

B    last_counter      = -2147483648

B    oldest_gap        = (2147483647,19700101000000)

B    time_of_last_sync = 20150421085222

B    MySysId           = 'ibis                04'

B  dbexpbuf[EXP_SHB]: buffer EIBUF installed with

B    semkey             = 35

B    shmkey             = 54

B    wp_n               = 18

B    sclass             = 0

B    block_length       = 512

B    max_objects        = 2000

B    max_obj_size       = 1896512

B    pref_obj_size      = 0

B    est_large_obj_size = 512000

B    free_vec_lg        = 1001

B    hash_vec_size      = 4001

B    buffer_l           = 8388608

B    max_blocks         = 14818

B    free_blocks        = 14818

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               = 18

B    sclass             = 0

B    block_length       = 512

B    max_objects        = 2000

B    max_obj_size       = 851904

B    pref_obj_size      = 0

B    est_large_obj_size = 8192

B    free_vec_lg        = 17

B    hash_vec_size      = 4001

B    buffer_l           = 4194304

B    max_blocks         = 6657

B    free_blocks        = 6657

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               = 18

B    sclass             = 10

B    block_length       = 512

B    max_objects        = 1500

B    max_obj_size       = 619584

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         = 4842

B    free_blocks        = 4842

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               = 18

B    sclass             = 13

B    block_length       = 256

B    max_objects        = 2000

B    max_obj_size       = 851648

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         = 13310

B    free_blocks        = 13310

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  NTAB: version is VERS_B, UNICODELG=2, SAP_UC_LN=2

I  MPI: dynamic quotas disabled.

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

M  Semaphore recovery: keep semaphore data.

M  logoff_check: set cancel flag during logoff.

M  PfInitMemory: version = 1

M  PfInitMemory: stat/recex/memory_check = 0

M  PfInitMemory: stat/rfcrec = 5, distinct = 0, depth = 5

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 000000001209CBF0

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 0000000040AF00D0

S  doing lock recovery

S  setting server cache root

S  found spool memory service RSPO-SERVERCACHE at 0000000040AF0650

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: 23044kb, dir_size: 22236kb.

A  Attached to PXA (address 00007FFFEDAE0050, size 300000K, 1 fragments of 276956K )

A  PXA allocated (address 00007FFFEDAE0050, size 300000K)

A  abap/pxa = shared protect gen_remote

A  PXA: checking structure sizes: 888|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=000007DFDF192000 leng=20955136 end=000007DFE058E000)

A  >> Shm MMADM area (addr=000007DFDF689B60 leng=242240 end=000007DFDF6C4DA0)

A  >> Shm MMDAT area (addr=000007DFDF6C5000 leng=15503360 end=000007DFE058E000)

A  RFC Destination> destination ibis_SM8_04 host ibis system SM8 systnr 4 (ibis_SM8_04)

A  RFC Options> H=ibis,S=04,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>' [SYBASE:721.02]):

B   max_blocking_factor       =  50,  min_blocking_factor         =   1,

B   max_in_blocking_factor    = 128,  min_in_blocking_factor      =   1,

B   max_union_blocking_factor =  50,  min_union_blocking_factor   =   1,

B   prefer_union_all          =   0,  prefer_join                 =   0,

B   prefer_fix_blocking       =   0,  prefer_in_itab_opt          =   1,

B   convert AVG               =   1,  alias table FUPD            =   0,

B   escape_as_literal         =   0,  ignore_maxmarkercnt         =   0,

B   select *                  =0x0f,  character encoding          = STD / []:X,

B   use_hints                 = abap->1, dbif->0x1, upto->0

M  ThrCreateShObjects allocated 37436 bytes at 0000000002FA0050

Y  dyWpInit

Y    ztta/dynpro_ara 800000

Y    ztta/cua_ara    500000

Y    ztta/diag_ara   250000

N  SsfSapSecin: getenv(SECUDIR)=="E:\usr\sap\SM8\DVEBMGS04/sec"

N 

N  =================================================

N  === SSF INITIALIZATION:

N  ===...SSF Security Toolkit name SAPSECULIB .

N  ===...SSF library is E:\usr\sap\SM8\DVEBMGS04\exe\sapcrypto.dll .

N  ===...SSF default hash algorithm is SHA1 .

N  ===...SSF default symmetric encryption algorithm is DES-CBC .

N  ===...SECUDIR="E:\usr\sap\SM8\DVEBMGS04/sec"

N  ===...loading of Security Toolkit successfully completed.

N  ===   CommonCryptoLib (SAPCRYPTOLIB) Version 8.4.34 pl40 (Feb 11 2015) MT-safe

N  =================================================

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.402.20020600]

W    ITS Plugin: Int.version, [34]

W    ITS Plugin: Feature set: [32]

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  SignInit: Not attempted to load Kerberos Library (ABAP parts missing, note 1798979)

N  VSI: WP init in ABAP VM completed with rc=0

E  EnqId_Initialize: local EnqId initialization o.k.

M 

M Tue Apr 21 08:52:26 2015

M  ***LOG Q0I=> NiPConnect2: 127.0.0.1:65000: connect (10061: WSAECONNREFUSED: Connection refused) [nixxi.cpp 3283]

M  *** ERROR => NiPConnect2: SiPeekPendConn failed for hdl 1/sock 1416

    (SI_ECONN_REFUSE/10061; I4; ST; 127.0.0.1:65000) [nixxi.cpp    3283]

M  *** ERROR => IcmConnect: NiConnect to localhost:65000,-1 (rc=-10) [icxxext.c    182]

M  *** ERROR => ThPlgConnectToIcm: IcmConnect failed (-10) [thxxplg.c    5165]

M  in_ThErrHandle: 1

M  *** ERROR => ThStart: connect to icman (step 1, th_errno 2, action 3, level 1) [thxxhead.c   11560]

M 

M  Info for wp 0

M 

M    pid = 4656

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    locked semaphores (), locking ()

M    act_cs_count = 1

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 4656) [dpnttool.c   339]

[Reagan]

There must be an issue with the ICM. Check the ICM trace file.

1934023 - Application server startup fail with an ICM connection error

[manumohandas82]

Hi  ,

Did you try Log off from the installation terminal  Loggin in  once again and repeat the installation ? / restart the server

If yes  , Post your dev_disp and dev_w0 from location /usr/sap/<SID>/<ISTANCE>/work/ directory

Thanks ,

Manu

[former_member182657]

If possible could you share dev_disp as well & size of page file configured for the system.

Thanks,

[ibrahim_yooseff]

hi Gaurav,

where can i find this dev_disp ? my ram size is 16gb and i have given swap size of 40 gb

[Former Member]

You will find the logs under work directory. Please attach WP logs as well.

[former_member182657]

Hi,

where can i find this dev_disp

In similar directory /usr/sap/SM8/DVEBMGS04/work

[former_member182657]

Hi Ibrahuim,

           CJ

SlibModule::writeError_impl() 
CJS-30149  ABAP processes of instance SM8/DVEBMGS04 [ABAP: STARTING] did not start after 10:10 minutes. Giving up.

Have you tried restart of complete system,if not try to restart complete system & do a check again.In addition please follow similar SCN thread

Regards,

[srinivasan_vinayagam]

Hi Ibrahim,

Share the sapinst_dev log and try to start SAP manually before starting SAP check the database whether start or not.

Regards,

V Srinivasan

[ibrahim_yooseff]

hi srinivasan,

TRACE      2015-04-20 09:41:55.598

NWDIState.isRunning() done: false

TRACE      2015-04-20 09:41:55.598

NWDIState.assertTimeout()

TRACE      2015-04-20 09:41:55.598

NWDialogInstance.getMaxWaitTime(true)

TRACE      2015-04-20 09:41:55.598

NWDialogInstance.getMaxWaitTime() done: 1200

TRACE      2015-04-20 09:41:55.598

NWDIState.assertABAPTimeout(600)

TRACE      2015-04-20 09:41:55.598

NWInstState.getElapsedString()

TRACE      2015-04-20 09:41:55.598

NWInstState.getElapsedString() done: 10:10

TRACE      2015-04-20 09:41:55.598

NWException thrown: nw.progress.waitingForStartABAPFailed:

ABAP processes of instance SM8/DVEBMGS04 [ABAP: STARTING] did not start after 10:10 minutes. Giving up.

TRACE      2015-04-20 09:41:55.598

Function setMessageIdOfExceptionMessage: nw.progress.waitingForStartABAPFailed

ERROR      2015-04-20 09:41:55.598

           CJSlibModule::writeError_impl()

CJS-30149  ABAP processes of instance SM8/DVEBMGS04 [ABAP: STARTING] did not start after 10:10 minutes. Giving up.

TRACE      2015-04-20 09:41:55.598 [jsextension.hpp:1142]

           CallFunctionBase::call()

Member function 'Installer.invokeModuleCall() has thrown a module error. Rethrowing.

ERROR      2015-04-20 09:41:55.848 [csistepexecute.cpp:1187]

FCO-00011  The step start with step key |NW_Onehost|ind|ind|ind|ind|0|0|NW_Onehost_System|ind|ind|ind|ind|onehost|0|NW_CI_Instance|ind|ind|ind|ind|ci|0|NW_CI_Instance_Start|ind|ind|ind|ind|start|0|start was executed with status ERROR ( Last error reported by the step: ABAP processes of instance SM8/DVEBMGS04 [ABAP: STARTING] did not start after 10:10 minutes. Giving up.).

TRACE      2015-04-20 09:41:55.895 [ckdbtablecontainer.cpp:93]

           CKdbTableContainer::syncToContainerFile

CKdbTableContainer::syncToContainerFile start ...

TRACE      2015-04-20 09:41:55.989 [ckdbtablecontainer.cpp:121]

           CKdbTableContainer::syncToContainerFile

after creating out stream  for D:\Program Files\sapinst_instdir\SOLMAN71\SYSTEM\SYB\CENTRAL\AS\statistic.xml

TRACE      2015-04-20 09:41:56.67 [ckdbtablecontainer.cpp:155]

           CKdbTableContainer::syncToContainerFile

CKdbTableContainer::syncToContainerFile stop ...

TRACE      2015-04-20 09:41:56.67 [syxxcfile.cpp:85]

           CSyFileImpl::decideIfMoveCopyNode(const CopyMoveDestinationInfo & {m_nodeTypeForCombiCheck: ..., m_path: D:/Program Files/sapinst_instdir/SOLMAN71/SYSTEM/SYB/CENTRAL/AS/__instana_tmp.12.xml, m_realNodeType: 8}, ISyNode::CopyMoveMode_t 0x3, PSyNodeInt &) const 

           lib=syslib module=syslib

Target node does not exist and (mode & ISyNode::MISSING) ==> I will copy/move.

TRACE      2015-04-20 09:41:56.67 [syxxcnode.cpp:425]

           CSyNodeImpl::move(const CSyPath & D:/Program Files/sapinst_instdir/SOLMAN71/SYSTEM/SYB/CENTRAL/AS/__instana_tmp.12.xml, ISyNode::CopyMoveMode_t 0x3)

           lib=syslib module=syslib

Moved D:/Program Files/sapinst_instdir/SOLMAN71/SYSTEM/SYB/CENTRAL/AS/__instana_tmp.xml to D:/Program Files/sapinst_instdir/SOLMAN71/SYSTEM/SYB/CENTRAL/AS/__instana_tmp.12.xml

INFO       2015-04-20 09:41:56.67 [synxcpath.cpp:799]

           CSyPath::createFile() lib=syslib module=syslib

Creating file D:\Program Files\sapinst_instdir\SOLMAN71\SYSTEM\SYB\CENTRAL\AS\__instana_tmp.xml.

TRACE      2015-04-20 09:41:56.833 [cstatisticmanager.cpp:2226]

           CStatisticManager::writeInstallationSlanaFile_Intern

TRACE      2015-04-20 09:41:56.833 [syxxcfile.cpp:85]

           CSyFileImpl::decideIfMoveCopyNode(const CopyMoveDestinationInfo & {m_nodeTypeForCombiCheck: ..., m_path: D:/Program Files/sapinst_instdir/SOLMAN71/SYSTEM/SYB/CENTRAL/AS/instslana.12.xml, m_realNodeType: 8}, ISyNode::CopyMoveMode_t 0x3, PSyNodeInt &) const 

           lib=syslib module=syslib

Target node does not exist and (mode & ISyNode::MISSING) ==> I will copy/move.

TRACE      2015-04-20 09:41:56.848 [syxxcnode.cpp:425]

           CSyNodeImpl::move(const CSyPath & D:/Program Files/sapinst_instdir/SOLMAN71/SYSTEM/SYB/CENTRAL/AS/instslana.12.xml, ISyNode::CopyMoveMode_t 0x3)

           lib=syslib module=syslib

Moved D:/Program Files/sapinst_instdir/SOLMAN71/SYSTEM/SYB/CENTRAL/AS/instslana.xml to D:/Program Files/sapinst_instdir/SOLMAN71/SYSTEM/SYB/CENTRAL/AS/instslana.12.xml

INFO       2015-04-20 09:41:56.848 [synxcfile.cpp:149]

           CSyFileImpl::removeEx(ISyFSErrorHandler * pErrorHandler)

           lib=syslib module=syslib

Removed file D:\Program Files\sapinst_instdir\SOLMAN71\SYSTEM\SYB\CENTRAL\AS\instslana.xml.

INFO       2015-04-20 09:41:56.848 [synxcpath.cpp:799]

           CSyPath::createFile() lib=syslib module=syslib

Creating file D:\Program Files\sapinst_instdir\SOLMAN71\SYSTEM\SYB\CENTRAL\AS\instslana.xml.

TRACE      2015-04-20 09:41:56.911

SAPInst calls the LogInquirer. The output of the LogInquirer can be found in file sapinst_loginquirer.log.

TRACE      2015-04-20 09:41:56.958 [iaxxgenimp.cpp:638]

            CGuiEngineImp::showMessageBox()

<html> <head> </head> <body> <p> An error occurred while processing option <i>SAP Solution Manager 7.1 Support Release 1 > SAP Systems > SAP ASE > Central System > Central System( Last error reported by the step: ABAP processes of instance SM8/DVEBMGS04 [ABAP: STARTING] did not start after 10:10 minutes. Giving up.)</i>. You can now: </p> <ul> <li> Choose <i>Retry</i><br>to repeat the current step. </li> <li> Choose <i>Log Files</i><br>to get more information about the error. </li> <li> Stop the option and continue later. </li> </ul> <p> Log files are written to D:\Program Files/sapinst_instdir/SOLMAN71/SYSTEM/SYB/CENTRAL/AS. </p> </body></html>

TRACE      2015-04-20 09:41:56.958 [iaxxgenimp.cpp:1031]

           CGuiEngineImp::acceptAnswerForBlockingRequest

Waiting for an answer from GUI

[ibrahim_yooseff]

i am sending it by split i am pasting it from the bottom of sapinst_dev file

NWInstance(DVEBMGS04/ibis)._callSAPControlUncheckedOutput(false, [GetProcessList], false, false, undefined)

TRACE      2015-04-20 09:41:55.536

NW.getSAPControlPath()

TRACE      2015-04-20 09:41:55.536

NW.getSAPControlPath() done: E:/usr/sap/SM8/ASCS05/exe/sapcontrol.exe

TRACE      2015-04-20 09:41:55.536

NWInstance(DVEBMGS04/ibis).isRunningLocally()

TRACE      2015-04-20 09:41:55.536

NWInstance.isServiceClustered()

TRACE      2015-04-20 09:41:55.536

NWInstance._getParameter(isServiceClustered)

TRACE      2015-04-20 09:41:55.536

NWInstance._getParameter() done: Property(isServiceClustered, false)

TRACE      2015-04-20 09:41:55.536

NWInstance.isServiceClustered() done: false

TRACE      2015-04-20 09:41:55.536

NetworkMgt.isHostLocal(ibis)

TRACE      2015-04-20 09:41:55.536

NetworkMgt.isHostLocal(ibis) done: true

TRACE      2015-04-20 09:41:55.536

NWInstance(DVEBMGS04/ibis).isRunningLocally() done: true

INFO       2015-04-20 09:41:55.551

           CJSlibModule::writeInfo_impl()

Node sapcontrol_SM8_DVEBMGS04.log already exists.

TRACE      2015-04-20 09:41:55.551 [synxcchapp.cpp:275]

           CSyChildApplicationImpl::doStart() lib=syslib module=syslib

Going to call CreateProcess/CreateProcessAsUser for 'E:\usr\sap\SM8\ASCS05\exe\sapcontrol.exe' now.

TRACE      2015-04-20 09:41:55.551 [synxcchapp.cpp:575]

           CSyChildApplicationImpl::doStart() lib=syslib module=syslib

Trying to start E:\usr\sap\SM8\ASCS05\exe\sapcontrol.exe CSySysLibCallsWrapper::syscallwrapper()->__CreateProcess__(NULL, <command line for executable E:\usr\sap\SM8\ASCS05\exe\sapcontrol.exe, NULL, NULL, TRUE, 0x420, NULL, NULL, &StartupInfo, &ProcessInfo)

TRACE      2015-04-20 09:41:55.551 [synxcchapp.cpp:653]

           CSyChildApplicationImpl::doStart() lib=syslib module=syslib

A child process has been started. Pid = 4568. Executable name: E:\usr\sap\SM8\ASCS05\exe\sapcontrol.exe

INFO       2015-04-20 09:41:55.551

           CJSlibModule::writeInfo_impl()

Output of E:\usr\sap\SM8\ASCS05\exe\sapcontrol.exe -prot PIPE -nr 04 -function GetProcessList is written to the logfile sapcontrol_SM8_DVEBMGS04.log.

TRACE      2015-04-20 09:41:55.583 [synxcpipe.cpp:163]

           CSyStdOutErrPipe::onUnderflow(void * buf, int maxBytes, int timeout)

           lib=syslib module=syslib

Syslib info about system call. OS message 109 (The pipe has been ended.

) after execution of system call 'ReadFile' with parameter ((CSySysLibCallsWrapper::syscallwrapper()->__read__ end of child process output pipe)), line (385) in file (d:\depot\bas\720_rel\bc_720-2_rel\gen\optu\ntamd64\ins\sapinst\impl\src\syslib\synxcpipe.cpp).

WARNING    2015-04-20 09:41:55.598

           CJSlibModule::writeWarning_impl()

Execution of the command "E:\usr\sap\SM8\ASCS05\exe\sapcontrol.exe -prot PIPE -nr 04 -function GetProcessList" finished with return code 3. Output:

20.04.2015 09:41:55

GetProcessList

OK

name, description, dispstatus, textstatus, starttime, elapsedtime, pid

disp+work.EXE, Dispatcher, GREEN, Running, Message Server connection ok, Dialog Queue time: 0.00 sec, 2015 04 20 09:33:16, 0:08:39, 4196

igswd.EXE, IGS Watchdog, GREEN, Running, 2015 04 20 09:33:16, 0:08:39, 4236

TRACE      2015-04-20 09:41:55.598

NWInstance._callSAPControlUncheckedOutput() done: 3

TRACE      2015-04-20 09:41:55.598

NWInstance._callSAPControlUnchecked() done: 3

TRACE      2015-04-20 09:41:55.598

NWInstance._callSAPControl() done: 3

TRACE      2015-04-20 09:41:55.598

NWInstance.allProcessesStarted() done: true

TRACE      2015-04-20 09:41:55.598

NWDIState.isRunning()

[ibrahim_yooseff]

cannot past it in one time due to the  file size

[former_member185954]

Hello Ibrahim,

Can you check the dev_w0 file in the work directory (/usr/sap/SM8/DVEBMGS04/work)

Can you zip the dev_w0 file into Winzip archive and attached the zipped file.

Regards,

Siddhesh

[ibrahim_yooseff]

@ siddesh will send you the zipped file aftersometime