It takes long time to start the server.

[Former Member]

We issue startsap command but we can only logon 15 mins later. We are using VMC on ABAP platform. We've got 10 application instances. Below is part of the trace file (trace level 2).

Who knows what is it doing?

TIA

James

A **GENER Trace switched on ***

A

A -PXA--

---

A PXA INITIALIZATION

A Sat Jan 16 11:44:55 2010

A PXA: Locked PXA-Semaphore.

A System page size: 4kb, total admin_size: 107124kb, dir_size: 26560kb.

I ShmKeyPermission( 6 ) = 0740 (octal)

I ShmKeyPermission( 6 ) = 0740 (octal)

I ShmProtect( 6, 3 )

I ShmProtect( key 6 valid )

I ShmProtect( slot Index 5 )

I ShmProtect( Mode: 0 )

I ShmProtect( before shmdt )

I ShmProtect( after shmdt )

I ShmProtect( before shmat 0x7000011c0000000)

I ShmProtect( after shmat )

I ShmProtect: shmat key 6 prot 3/0 done

I ShmCreate( 6, 1331200000, 2, -> 0x0x7000011c0000000 )

A Attached to PXA (address 0x7000011c0000000, size 1300000K, 4 fragments of 298220K )

A abap/pxa = shared unprotect gen_remote

A PXA INITIALIZATION FINISHED

A -PXA--

---

[Former Member]

We clean and reorg VBDATA and this problem gone.

[Former Member]

mean if we start whole landscape, it is quick

Did you have any automated script for start and stop process?

Seems like looping concept in the script may be the reason.....

Regards,

Nick Loy

[Former Member]

Can you please elloborate:

Is this happening only on DB+CI or on all apps servers(10 dialog instances while stating only application).

And also paste your landscape details, how many systems/applications(otherthan sap) connected to this.

Regards,

Nick Loy

[Former Member]

It happen to SAP CRM. DB and CI are seperated. I found the later we start the instance, the longer it takes. For example, CI needs 5 mins, app01 needs 10 mins..... app10 needs longer and longer.

SAP ECC connects the CRM through middleware.

IBM ESB and another SMS application connect to CRM through jCo.

VBDATA is huge, but rdisp/vbreorg = 0.

rdisp/bufrefmode = 'sendoff,exeauto' in DEFAULT.PFL

We are using VMC in crm.

We installed ABAP+Java dual stack but we disable Java from starting by setting instance profile.

[Former Member]

Hi James,

Couple of things to check here......

Is your CI and DB seperated by firewall ? If yes, please check firewall logs to see if some ports are getting blocked ?

I hope it is a production server....Since when you have these issues ? I mean whether you had these issues before ?

Is your CI and DB seperated by long physical network distance ?

We had similar issues which we resolved checking firewall logs and by applying go-live check report recommendations.

Revert with above information.

Cheers....,

Raghu

[Former Member]

Raghu

DB and CI are in the same network, no fireware between.

It happen to production but I do not know exactly since when it happen.

I noticed when there is no transaction data, then it start quickly. I mean if we start whole landscape, it is quick. If all servers are running but I just restart one of them, then it takes long to that one.

[Former Member]

I noticed most time is for below activity:

M ThrCreateShObjects allocated 143410 bytes at 0x70000001374a000

M SosRegisterMemAddr: add mem addr 0x70000001374a000 / >thr_serv_info<

M SosRegisterMemAddr: add mem addr 0x70000001374a01c / >thr_wpadm<

M ThrCreateShObjects o.k.

M SosRegisterMemAddr: add mem addr 0x113299000 / >ztta<

M SosRegisterMemAddr: alloc/realloc table

M SosRegisterMemAddr: add mem addr 0x1136b27a0 / >spa<

M ThrRegisterMemAddrs o.k.

I SemKeyPermission( 50 ) = 0740 (octal)

I SemKeyPermission( 50 ) = 0740 (octal)

M Sat Jan 16 11:59:36 2010

[Former Member]

A

M SosRegisterHook: add hook >ATRA switch dynamic trace(0x11068a360)< for event RSTR_SWITCH_CHANGE

M SosRegisterHook: add hook >abTpdaThHook_AfterRollIn(0x110677808)< for event AFTER_ROLL_IN

M SosRegisterHook: add hook >abTpdaThHook_EModeEnded(0x110677820)< for event CANCEL_TRANSACTION

M SosRegisterHook: add hook >abTpdaThHook_EModeEnded(0x110677820)< for event BEFORE_SESSION_END

M SosRegisterHook: add hook >abRtmClearSession(0x110669138)< for event BEFORE_SESSION_END

M SosRegisterHook: add hook >abRtmClearSession(0x110669138)< for event BEFORE_SESSION_CANCEL

M SosRegisterHook: add hook >abRtmRollOut(0x110669150)< for event BEFORE_ROLL_OUT

M SosRegisterHook: add hook >abRtmRollIn(0x110669168)< for event AFTER_ROLL_IN

C DbSlRead(): table='DDNTT'

C OCIStmtExecute() completed, rc=100=OCI_NO_DATA, no further data

C -> rc=1403=OCI_ERR_NOT_FOUND

[Former Member]

C In 00: DBSL_DATA_CHAR (len=60, max=60, dec=0)

C Out 00: DBSL_DATA_CHAR (len=2, max=2, dec=0)

C Out 01: DBSL_DATA_RAW (len=16, max=16, dec=0)

C Out 02: DBSL_DATA_CHAR (len=28, max=28, dec=0)

C Out 03: DBSL_DATA_CHAR (len=28, max=28, dec=0)

C Out 04: DBSL_DATA_CHAR (len=28, max=28, dec=0)

C Out 05: DBSL_DATA_INTEGER_2 (len=2, max=2, dec=0)

C Out 06: DBSL_DATA_INTEGER_4 (len=4, max=4, dec=0)

C Out 07: DBSL_DATA_INTEGER_2 (len=2, max=2, dec=0)

C Out 08: DBSL_DATA_INTEGER_2 (len=2, max=2, dec=0)

C Out 09: DBSL_DATA_INTEGER_2 (len=2, max=2, dec=0)

C Out 10: DBSL_DATA_CHAR (len=2, max=2, dec=0)

C Out 11: DBSL_DATA_CHAR (len=2, max=2, dec=0)

C Out 12: DBSL_DATA_CHAR (len=60, max=60, dec=0)

C Out 13: DBSL_DATA_RAW (len=6, max=6, dec=0)

C Out 14: DBSL_DATA_CHAR (len=2, max=2, dec=0)

C Out 15: DBSL_DATA_INTEGER_2 (len=2, max=2, dec=0)

C Out 16: DBSL_DATA_INTEGER_2 (len=2, max=2, dec=0)

C Out 17: DBSL_DATA_INTEGER_2 (len=2, max=2, dec=0)

C Out 18: DBSL_DATA_INTEGER_2 (len=2, max=2, dec=0)

C Out 19: DBSL_DATA_INTEGER_2 (len=2, max=2, dec=0)

C Out 20: DBSL_DATA_INTEGER_2 (len=2, max=2, dec=0)

[Former Member]

C bind_type_and_length(): 1 input variables given

C bind_type_and_length(): 21 output variables given

C OCIStmtExecute() completed, rc=100=OCI_NO_DATA, no further data

C -> rc=1403=OCI_ERR_NOT_FOUND

C In 00: DBSL_DATA_CHAR (len=60, max=60, dec=0)

C Out 00: DBSL_DATA_CHAR (len=60, max=60, dec=0)

C Out 01: DBSL_DATA_INTEGER_2 (len=2, max=2, dec=0)

C Out 02: DBSL_DATA_INTEGER_4 (len=4, max=4, dec=0)

C Out 03: DBSL_DATA_RAW (len=32768, max=32768, dec=0)

C bind_type_and_length(): 1 input variables given

C bind_type_and_length(): 4 output variables given

C OCIStmtExecute() completed, rc=100=OCI_NO_DATA, no further data

C -> rc=1403=OCI_ERR_NOT_FOUND

M SosRegisterHook: add hook >ab_SosShmBeforeCommit(0x11068a258)< for event BEFORE_COMMIT

M ThSchedRegisterFuncPtr: registered ab_ShmStartConstructor(at 0x11068a270) for index 1

M ThSchedRegisterFuncPtr: registered ab_ShmRefreshDelayed(at 0x11068a288) for index 2

M ThSchedRegisterFuncPtr: registered ab_ShmInvalidateDelayed(at 0x11068a2a0) for index 3

M ThSchedRegisterFuncPtr: registered ab_ShmIdleTimePassed(at 0x11068a2b8) for index 4

X MmxRegisterRscAdm 9 0x11068a2d0 0x11068a2e8

[Former Member]

M RmRegisterResHandler: register resource handler 0x11068a300 for key 10

M RmRegisterResHandler: register resource handler 0x11068a318 for key 12

X MmxRegisterRscProtect 9 0x11068a330 4096

I SemKeyPermission( 59 ) = 0740 (octal)

I SemKeyPermission( 59 ) = 0740 (octal)

X EsMprotect: mprotect(0x700000f50372000 4096 0)

X EsMprotect: mprotect(0x700000f5356f000 4096 0)

A ABAP ShmAdm attached (addr=0x700000f50373000 leng=52412416 end=0x700000f5356f000)

A >> Shm MMADM area (addr=0x700000f50ebd730 leng=624192 end=0x700000f50f55d70)

A >> Shm MMDAT area (addr=0x700000f50f56000 leng=39948288 end=0x700000f5356f000)

X EsMprotect: mprotect(0x700000f50f56000 39948288 1)

A RFC: wait time before rollout: 500 ms

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

A RFC rfc/bc_ignore_thcmaccp_retcode not set, use default value: 0

M ThRegisterSoftCancelRt: register handler

M PfRegisterHook: add hook >rfc_stat_hook< for event WR_RFC_SERV_DEST_REC

[Former Member]

A RFC Method> initialize RemObjDriver for ABAP Objects

M ThJRegNatives3: registered natives for class >com.sap.vmc.krn.rfcserver.RfcServer< (1 functions) immediately

M set lg_timeout to 10000

X MmxInit( 0x700000f535ba190 16384 4 0xfffffffffffdba0 24 ) 8 24 56 56

M SosRegisterHook: add hook >ab_SosRfcBeforeCommit(0x11067cfb0)< for event BEFORE_COMMIT

A RFC register before commit hook o.k.

M SosRegisterHook: add hook >ab_SosRfcBeforeRollback(0x11067cfc8)< for event BEFORE_ROLLBACK

A RFC register before rollback hook o.k.

A IMC> RmRegisterResHandler: RM_MODE_COMM

M RmRegisterResHandler: register resource handler 0x11067d1f0 for key 4

M SosRegisterHook: add hook >IMCClearSpaDummy(0x11067d208)< for event AFTER_CREATE_INT_MODE

M SosRegisterHook: add hook >ImcResetPtr(0x11067d220)< for event BEFORE_TASK_SWITCH

M SosRegisterHook: add hook >ImcClearSession(0x11067d238)< for event CLEAR_SESSION

M SosRegisterHook: add hook >ImcClearSession(0x11067d238)< for event CANCEL_TRANSACTION

M SosRegisterHook: add hook >HttpResetPtr(0x11067d0a0)< for event BEFORE_TASK_SWITCH

M SosRegisterHook: add hook >HttpClearSession(0x11067d0b8)< for event CLEAR_SESSION

M SosRegisterHook: add hook >HttpClearSession(0x11067d0b8)< for event CANCEL_TRANSACTION

M SosRegisterHook: add hook >HttpClearSession(0x11067d0d0)< for event BEFORE_SESSION_END

M SosRegisterHook: add hook >HttpDeleteClient(0x11067d0e8)< for event BEFORE_DELETE_INT_MODE

M SosRegisterHook: add hook >HttpClearSession(0x11067d0d0)< for event BEFORE_SESSION_CANCEL

H HTTP> Parameter icf/ssocookie_mandatory set to 0

M ThPlgRegister: register handler for protocol 1 (HTTP)

M ThPlgRegister: register handler for protocol 2 (HTTPS)

M ThPlgRegister: register handler for protocol 4 (SMTP)

[Former Member]

B { db_setget( cid = 65535, fcode = 'RT_SETB', tname = 'SVERS' ) {sapicc.c:1293}

B dbtrtab INFO (init_connection '<DEFAULT>'/5):

B cut blanks = 0x1, select * = 0x0f, character encoding = STD / <none>:-

B } db_setget( fcode = 'RT_SETB', retcode = 0 )

B { db_setget( cid = 0, fcode = 'RT_GET', tname = 'SVERS' ) {sapicc.c:1297}

B } db_setget( fcode = 'RT_GET', retcode = 0 )

B { db_setget( cid = 0, fcode = 'RT_RELEASE', tname = 'SVERS' ) {sapicc.c:1299}

B } db_setget( fcode = 'RT_RELEASE', retcode = 0 )

B { db_setget( cid = 65535, fcode = 'RT_SETB', tname = 'SVERS' ) {abinit.c:2611}

B } db_setget( fcode = 'RT_SETB', retcode = 0 )

B { db_setget( cid = 0, fcode = 'RT_GET', tname = 'SVERS' ) {abinit.c:2615}

B } db_setget( fcode = 'RT_GET', retcode = 0 )

B { db_setget( cid = 0, fcode = 'RT_RELEASE', tname = 'SVERS' ) {abinit.c:2617}

B } db_setget( fcode = 'RT_RELEASE', retcode = 0 )

B db_con_commit (con_da={R/3,0,0},th_commit=1,tx=0,hold_cursor=0)

M ab_init o.k.

M ThrInitGlobals o.k.

I ShmGet( 10, 30, 143410, 3, -> 0x0x70000001374a000 )

I ShmProtect( 30, 3 )

I ShmProtect( key 30 valid )

I ShmProtect( slot Index 29 )

[Former Member]

I ShmProtect: Key=30 not attached

I ShmProtect( 30, 3 )

I ShmProtect( key 30 valid )

I ShmProtect( slot Index 29 )

I ShmProtect( Mode: -10 )

I ShmProtect( SegSlotIdx: 29 )

I ShmCreate( 30, 143410, 3, -> 0x0x70000001374a000 )

M ThrCreateShObjects allocated 143410 bytes at 0x70000001374a000

M SosRegisterMemAddr: add mem addr 0x70000001374a000 / >thr_serv_info<

M SosRegisterMemAddr: add mem addr 0x70000001374a01c / >thr_wpadm<

M ThrCreateShObjects o.k.

M SosRegisterMemAddr: add mem addr 0x113299000 / >ztta<

M SosRegisterMemAddr: alloc/realloc table

M SosRegisterMemAddr: add mem addr 0x1136b27a0 / >spa<

M ThrRegisterMemAddrs o.k.

I SemKeyPermission( 50 ) = 0740 (octal)

I SemKeyPermission( 50 ) = 0740 (octal)

M Sat Jan 16 11:59:36 2010

[Former Member]

M ThJRegNatives3: registered natives for class >com.sap.vmc.krn.java2abap.Java2Abap< (1 functions) lazy

M ThrInitRunTime: ThrtRegJavaNatives o.k.

M ThJRegNatives3: registered natives for class >com.sap.vmc.tracing.WpFileWriter< (5 functions) lazy

M ThrInitRunTime: ThrtRegWpWriterJavaNatives o.k.

M ThJRegNatives3: registered natives for class >com.sap.vmc.krn.wpinfo.Wp< (6 functions) lazy

M ThrInitRunTime: ThrtHttpRegWpJavaNatives o.k.

M ThJRegNatives3: registered natives for class >com.sap.vmc.krn.usrinfo.Usr< (9 functions) lazy

M ThrInitRunTime: ThrtHttpRegUsrJavaNatives o.k.

M ThJRegNatives3: registered natives for class >com.sap.vmc.krn.meminfo.Mem< (2 functions) lazy

M ThrInitRunTime: ThrtHttpRegMemJavaNatives o.k.

M ThJRegNatives3: registered natives for class >com.sap.vmc.krn.sysinfo.SapSys< (23 functions) lazy

M ThrInitRunTime: ThrtHttpRegSysJavaNatives o.k.

M ThrInitRunTime o.k.

Y dynpStartupdyRegisterHooks

M SosRegisterHook: add hook >dyRollInOutHook(0x11067d250)< for event AFTER_ROLL_IN

M SosRegisterHook: add hook >dyRollInOutHook(0x11067d250)< for event BEFORE_ROLL_OUT

M SosRegisterHook: add hook >dyRollInOutHook(0x11067d250)< for event BEFORE_DELETE_INT_MODE

M SosRegisterHook: add hook >dyRollInOutHook(0x11067d250)< for event AFTER_CREATE_INT_MODE

M SosRegisterHook: add hook >dyKeyTableRest(0x11067d268)< for event AFTER_COMMIT

M SosRegisterHook: add hook >dyKeyTableReset(0x11067d268)< for event BEFORE_ROLLBACK

M ThSchedRegisterFuncPtr: registered dy_dbupd(at 0x11067d280) for index 5

M ThrtDynpStartup o.k.

[Former Member]

A A Initialize Task.

A + not rolled in

X EmAlloc: Imode=0

X SHM2_EsCreate: ====================

X SHM2_EsCreate: UserInfo=EM-CONTEXT Blocks=1 BlockCurrent=81

X map_get: shmget(IPC_PRIVATE, 4096MB, 022600) = 626003247

X FreeListIndex = 0x29

X ESSHM: UpdCounters BlockCurrent=114 Changed=0 (BPS=2 Avg=3) SegCurrent=40 Changed=1

X esSHMInitSegment BlocksFree=1023

X ESSHM: UpdCounters BlockCurrent=118 Changed=1 (BPS=2 Avg=3) SegCurrent=42 Changed=0

X SHM2_EsCreate: return: handle=40 Addr=0x700000050100000 Context=19

X MmxInit( 0x700000050100000 4194304 7 0xfffffffffffda90 8 ) 8 24 56 56

A ab_resize_imode(): 1024 100000 4189848 0x700000050100a38

X MmxInit( 0x700000050100a38 4189848 3 (nil) 0 ) 8 24 56 56

M ab_startup o.k.

N SsfSapSecin: putenv(SECUDIR=/usr/sap/CPD/D88/sec): ok