Issue in SAP startup in XPRA_EXECUTION phase

[tamil_arasan]

Dear experts,

we are getting error while upgrading using SUM tool to EHP7 in phase XPRA_Execution.

Disp+work is running and status is green however we are unable to logon to the system as workprocesses status is empty.

we are getting the error message in DEV_W* as " PXA APG: skipping current run due to transport activities".

Kernel release 7.40 SP 37

message server is also working fine

DEV_W* log:

AppServerTimeSync, getDBsynctime_strict():

A    returning successfully with

A    Localtime: 1397126131, DBTime: 1397126131.

A    Duration of DB calls(microsecs): DBTime1: 534, DBTime2: 297.

A  AppServerTimeSync, zdate_gettime():

A    New bias computed: 0.

S

S Thu Apr 10 20:36:31 2014

S  found spool memory service RSPO-ACTIONS at 70000423000a6a0

A

A Thu Apr 10 20:37:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 20:41:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 20:43:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 20:45:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 20:47:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 20:49:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 21:01:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 21:03:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 21:05:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 21:05:31 2014

A  AppServerTimeSync, getDBsynctime_strict():

A    returning successfully with

A    Localtime: 1397127931, DBTime: 1397127931.

A    Duration of DB calls(microsecs): DBTime1: 612, DBTime2: 312.

A  AppServerTimeSync, zdate_gettime():

A    New bias computed: 0.

A

A Thu Apr 10 21:07:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 21:09:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 21:21:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 21:39:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 21:51:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 21:53:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 21:55:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 21:57:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 21:59:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 22:01:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 22:03:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 22:05:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 22:05:31 2014

A  AppServerTimeSync, getDBsynctime_strict():

A    returning successfully with

A    Localtime: 1397131531, DBTime: 1397131531.

A    Duration of DB calls(microsecs): DBTime1: 790, DBTime2: 1923.

A  AppServerTimeSync, zdate_gettime():

A    New bias computed: 0.

A

A Thu Apr 10 22:07:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 22:09:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 22:21:30 2014

A  PXA APG: skipping current run due to transport activities

A

A Thu Apr 10 22:23:30 2014

A  PXA APG: skipping current run due to transport activities

Kindly help on this.

Thanks a lot!,

Pradeep

[tamil_arasan]

Hi All,

Solved by firewall settings.

Thanks a lot RB and Deepak!!

Thanks and regards,

Pradeep

[Reagan]

The SUM tool will logs for each phase in the upgrade directory.

So check the logs for this phase at <DIR_PUT>/abap/log directory.

Regards

RB

[tamil_arasan]

Hi RB,

we don't find any strange issues in the <DIR_PUT>/abap/log, but we got this message in the dev_W* log. RSecSSFs: Configuration value "rsec/ssfs_datapath" from profile explicitly overwritten by different value in environment variable RSEC_SSFS_DATAPATH

can you please suggest? we have checked environment variables and profile parameters everything is fine for SSFS.

Thanks and regards,

Pradeep

[Reagan]

Without trace files there is nothing much I can do for you.

I assume and suggest something which is to me that I am misleading you.

Regards

RB

[tamil_arasan]

Thanks RB,

Here is dev_w* entire log..there is no issues in dispatcher. we are in 7.40 kernel. kindly let me know the possible solutions for the error.

Thanks and regards,

Pradeep

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

trc file: "dev_w23", trc level: 1, release: "740"

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

*

*  ACTIVE TRACE LEVEL           1

*  ACTIVE TRACE COMPONENTS      all, MJ

*

M sysno      03

M sid        <SID>

M systemid   324 (IBM RS/6000 with AIX)

M relno      7400

M patchlevel 0

M patchno    37

M intno      20020600

M make       multithreaded, Unicode, 64 bit, optimized

M profile    /usr/sap/<SID>/SYS/profile/<SID>_DVEBMGS03_<hostname>

M pid        9568286

M

M 

M Tue Apr 15 21:22:31 2014

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

M  length of sys_adm_ext is 500 bytes

M  *** WARNING => NiIHdlSetParamNoSslSessionDone: call on non SSL connection [nixxi.cpp    11068]

M  ThStart: taskhandler started

M  ThInit: initializing SPO work process W23

M  ***LOG Q01=> ThInit, WPStart (Workp. 23 1 9568286) [thxxhead.c   896]

M 

M Tue Apr 15 21:22:34 2014

M  ThInit: running on host <hostname>

I  MtxInit: 23 0 0

M  calling db_connect ...

B  Loading DB library '/usr/sap/<SID>/SYS/exe/run/dboraslib.so' ...

B  Library '/usr/sap/<SID>/SYS/exe/run/dboraslib.so' loaded

B  Version of '/usr/sap/<SID>/SYS/exe/run/dboraslib.so' is "740.10", patchlevel (0.37)

B  read_con_info_ssfs(): DBSL supports extended connect protocol

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

C  Register application info.

C  Oracle client version: 11.2.0.3.0, V1, default build, (dbsl 740 300913, UNICODE[2])

C  Installed Oracle client patches:

C  # Patch  13508485     : Created on 21 Dec 2011, 13:23:38 hrs PST8PDT

C  # Patch Description: Created on 28 Dec 2011, 01:17:39 hrs PST8PDT

C  # Patch  11742262     : Created on  7 Mar 2012, 12:22:41 hrs CET

C  Client NLS setting (by OCINlsGetInfo(con=0)): 'AMERICAN_AMERICA.UTF16'

C  Connecting as SAPR3/<pwd>@<SID> on connection 0 (nls 0) ... (dbsl 740 300913, UNICODE[2])

C  Attaching to database server <SID> (con=0, svchp=1149532e0, srvhp=1149537f0)

C 

C Tue Apr 15 21:22:35 2014

C  Starting user session: OCISessionBegin(con=0, usr='SAPR3', svc=1149532e0, srv=1149537f0, usr=114999390)

C  Now 'SAPR3/<pwd>@<SID>' is connected: con=0, nls=0, session=629, time='2014-04-15 21:22:35'

C 

C Tue Apr 15 21:22:36 2014

C  DB instance <SID> is running on <hostname> with ORACLE version 11.2.0.3.0 since APR 15, 2014, 21:21:54.

C  con=0, V$NLS_PARAMETERS: NLS_LANG=AMERICAN_AMERICA.UTF8, NLS_NCHAR=UTF8

C  Nls CharacterSet                      NationalCharSet                   EnvHp            ErrHp            ErrBt          

C    0 UTF16                             AL16UTF16                         1149208d0        114950348        114951448      

B  Connection 0 opened (DBSL handle 0)

C     DbSlControl(DBSL_CMD_SAPRELEASE_SET,abap='740')

M  ThDbConnect: db_connect o.k.

X  EmInit: MmSetImplementation( 2 ).

X  MM global diagnostic options set: 0

X  EM/TOTAL_SIZE_MB = 12288

X  mm.dump: set maximum dump mem to 96 MB

B 

B Tue Apr 15 21:22:40 2014

B  db_con_shm_ini:  WP_ID = 23, WP_CNT = 30, CON_ID = -1

B 

B Tue Apr 15 21:22:41 2014

B  Start CursorInit

B  TBI initializing lock manager ...

B  TBI locking          : multiple locks

B  TBI lock manager impl: semamphore

B  dbtbxbuf: Buffer TBI64 (addr: 7000041200000f0, size: 1060224000, end: 70000415f31bcf0)

B  dbtbxbuf: Profile: max_objects = 181000, displace = 1, reorg = 0

B  dbtbxbuf: request_unit = 2000, sync_reload = 5, inval_reload = 5, parallel_penalty = 0

B  dbtbxbuf: protect_shm = 0, force_checks = 0

B  dbtbxbuf: tsize_retry = 0

B  dbtbxbuf: obj_entry_size = 224, nt_genkey_entry_size = 28

B  ***LOG BB0=> buffer TBI64      started with length 1060224000 bytes [dbtbxbuf     11368]

B  DBI: init TBI BUFFER (data):  start=700003f90301000  length=1017509888  end=700003fccd60800

B  dbprotocol: table logging switched on for all clients

B 

B Tue Apr 15 21:22:42 2014

B  FDA protocol switched OFF due to: transport/systemtype != SAP

B  dbsync[db_syinit]: shared memory successfully created and initialised, sync_adm_p = 700004130000000

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

B    oldest_gap        = (2147483647,19700101110000)

B    time_of_last_sync = 20140415212242

B    MySysId           = '<hostname>            03'

B  dbexpbuf[EXP_SHB]: Creating shared memory with segments

B    ADMIN             : 1            * 184   = 184

B    RECOVERY          : 120          * 40    = 4800

B    MUTEX VECTOR      : 600013       * 56    = 33600728

B    OBJECT DIRECTORY  : 300000       * 248   = 74400000

B    HASH VECTOR       : 600011       * 16    = 9600176

B    STATISTICS        : 1            * 152   = 152

B    FREELIST          : 33           * 8     = 264

B    DATA SPACE        : 1579676      * 512   = 808794112

B  dbexpbuf[EXP_SHB]: Shared memory successfully created and initialized

B  dbexpbuf[EXP_SHB]: buffer installed with the following properties

B    semKey             = 35

B    shmKey             = 54

B    wpCnt              = 30

B    blockSize          = 512

B    maxObjects         = 300000

B    maxObjectSize      = 202198528

B    freeListVectorSize = 33

B    hashVectorSize     = 600011

B    bufferSize         = 921600000

B    maxBlocks          = 1579676

B    freeBlocksCnt      = 1579676

B    mutexVectorSize    = 600013, ADMIN_MUTEX = 600011, INVAL_MUTEX = 600012

B    tracing            = 0

B    forceChecks        = 0

B    protectShm         = 0

B  dbexpbuf[EXP_SHM]: Creating shared memory with segments

B    ADMIN             : 1            * 184   = 184

B    RECOVERY          : 120          * 40    = 4800

B    MUTEX VECTOR      : 4003         * 56    = 224168

B    OBJECT DIRECTORY  : 2000         * 248   = 496000

B    HASH VECTOR       : 4001         * 16    = 64016

B    STATISTICS        : 1            * 152   = 152

B    FREELIST          : 17           * 8     = 136

B    DATA SPACE        : 6713         * 512   = 3437056

B  dbexpbuf[EXP_SHM]: Shared memory successfully created and initialized

B  dbexpbuf[EXP_SHM]: buffer installed with the following properties

B    semKey             = 56

B    shmKey             = 65

B    wpCnt              = 30

B    blockSize          = 512

B    maxObjects         = 2000

B    maxObjectSize      = 859264

B    freeListVectorSize = 17

B    hashVectorSize     = 4001

B    bufferSize         = 4194304

B    maxBlocks          = 6713

B    freeBlocksCnt      = 6713

B    mutexVectorSize    = 4003, ADMIN_MUTEX = 4001, INVAL_MUTEX = 4002

B    tracing            = 0

B    forceChecks        = 0

B    protectShm         = 0

B  dbexpbuf[EXP_CUA]: Creating shared memory with segments

B    ADMIN             : 1            * 184   = 184

B    RECOVERY          : 120          * 40    = 4800

B    MUTEX VECTOR      : 4003         * 56    = 224168

B    OBJECT DIRECTORY  : 2000         * 248   = 496000

B    HASH VECTOR       : 4001         * 16    = 64016

B    STATISTICS        : 1            * 152   = 152

B    FREELIST          : 587          * 8     = 4696

B    DATA SPACE        : 598512       * 512   = 306438144

B  dbexpbuf[EXP_CUA]: Shared memory successfully created and initialized

B  dbexpbuf[EXP_CUA]: buffer installed with the following properties

B    semKey             = 30

B    shmKey             = 47

B    wpCnt              = 30

B    blockSize          = 512

B    maxObjects         = 2000

B    maxObjectSize      = 76609536

B    freeListVectorSize = 587

B    hashVectorSize     = 4001

B    bufferSize         = 307200000

B    maxBlocks          = 598512

B    freeBlocksCnt      = 598512

B    mutexVectorSize    = 4003, ADMIN_MUTEX = 4001, INVAL_MUTEX = 4002

B    tracing            = 0

B    forceChecks        = 0

B    protectShm         = 0

B  dbexpbuf[EXP_OTR]: Creating shared memory with segments

B    ADMIN             : 1            * 184   = 184

B    RECOVERY          : 120          * 40    = 4800

B    MUTEX VECTOR      : 4003         * 56    = 224168

B    OBJECT DIRECTORY  : 2000         * 248   = 496000

B    HASH VECTOR       : 4001         * 16    = 64016

B    STATISTICS        : 1            * 152   = 152

B    FREELIST          : 33           * 8     = 264

B    DATA SPACE        : 13425        * 256   = 3436800

B  dbexpbuf[EXP_OTR]: Shared memory successfully created and initialized

B  dbexpbuf[EXP_OTR]: buffer installed with the following properties

B    semKey             = 55

B    shmKey             = 64

B    wpCnt              = 30

B    blockSize          = 256

B    maxObjects         = 2000

B    maxObjectSize      = 859200

B    freeListVectorSize = 33

B    hashVectorSize     = 4001

B    bufferSize         = 4194304

B    maxBlocks          = 13425

B    freeBlocksCnt      = 13425

B    mutexVectorSize    = 4003, ADMIN_MUTEX = 4001, INVAL_MUTEX = 4002

B    tracing            = 0

B    forceChecks        = 0

B    protectShm         = 0

B  ***LOG BB0=> buffer CALE       started with length 500000     bytes [dbcalbuf     2213]

M 

M Tue Apr 15 21:22:43 2014

M  SHM_PRES_BUF                                        (addr: 7000041d0000000, size: 100000768)

M  ThCreateNoBuffer                    allocated 822152 bytes for 1500 entries at 700004200000000

M  ThCreateNoBuffer                    index size: 4500 elems

M  ThCreateVBAdm                        allocated 32976 bytes (50 server) at 700004210000000

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

G  GetWritePermissionForShm( pLocation =  94, pEnforce = 1 )

G 

G Tue Apr 15 21:22:44 2014

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 114d48a60

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)   = 500

S  hostspool list size = 5000

S  option list size is 30

S      intervals: query=50, rescan=1800, global=300 info=120

S      init processing groups

S  InitGroups parm=rdisp/wp_no_spo_Snm_max

S  No SPOs are reserved for SNMP

S      processing queue enabled

S  creating spool memory service RSPO-RCLOCKS at 700004230000080

S  doing lock recovery

S  setting server cache root

S  using server cache size 100 (prof=100)

S  creating spool memory service RSPO-SERVERCACHE at 700004230000960

S    using messages for server info

B  dbtran INFO (init_connection '<DEFAULT>' [ORACLE:740.10]):

B   max_blocking_factor       =   5,  min_blocking_factor         =   5,

B   max_in_blocking_factor    =   5,  min_in_blocking_factor      =   5,

B   max_union_blocking_factor =   5,  min_union_blocking_factor   =   5,

B   prefer_union_all          =   0,  prefer_join                 =   0,

B   prefer_fix_blocking       =   0,  prefer_in_itab_opt          =   1,

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

B   escape_as_literal         =   1,                                  

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

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

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

M  ThrCreateShObjects                 allocated 62368 bytes at 700004240000000

M 

M Tue Apr 15 21:22:46 2014

M  ThVBStartUp: restart pending update requests

M  ThVBAutoStart: update-auto-delete

N 

N Tue Apr 15 21:22:49 2014

N  MskiCreateLogonTicketCache: Logon Ticket cache created in shared memory.

N  MskiCreateLogonTicketCache: Logon Ticket cache pointer registered in shared memory.

N  SignInitOnce: Security Context Cache created (max. 2500 entries, 1305600 bytes)

N  No SEC_CONTEXT_COPY records found for deletion

M  SecAudit(rsauinit): Start init of Security Audit Log for first wp.

M  SecAudit(rsauinit): New shared memory created and attached, size = 20448.

M  *** ERROR => SecAudit(RsauShmInit): parameter too small rsau/max_diskspace/local; replaced [rsauwr1.c    2273]

M  SecAudit(RsauShmInit): addr of SHM for Audit.... = 700004250000000

M  SecAudit(RsauShmInit): addr of RSAUSHM.......... = 700004250001000

M  SecAudit(RsauShmInit): addr of RSAUSLOTINFO..... = 7000042500019d0

M  SecAudit(RsauShmInit): addr of RSAUSLOTS........ = 7000042500019e0

M  SecAudit(RsauShmInit): SHM version.............. = 6

M  SecAudit(RsauShmInit): max size of one file..... = 0 KB

M  SecAudit(RsauShmInit): max size of all files.... = 102400 KB

M  SecAudit(RsauShmInit): number of slots available = 90

M  SecAudit(RsauShmInit): number of slots requested = 5

M  SecAudit(RsauShmInit): user selection........... = 0

M 

M Tue Apr 15 21:22:50 2014

M  SecAudit(LoadTSL1DCache): TSL1D cache loaded

M  SecAudit(RsauGetCurrentProfile): active audit profile ZSECMON

M  SecAudit(RsauGetCurrentProfile): Init of shared memory completed

M  ***LOG AV6=> 05& [rsauprof.c   211]

M  SecAudit(check_daily_file): RsauCheckLocalFileHandles() triggered

M  SecAudit(check_daily_file): audit file opened /usr/sap/<SID>/seclogs/audit_20140415

M  SsfSapSecin: automatic application server initialization for SAPSECULIB

N  SsfSapSecin: Looking for PSE in database

N  SsfPseLoad: started...(path=/usr/sap/<SID>/DVEBMGS03/sec, AS=<hostname>, instanceid=03)

N  SsfPseLoad: Downloading file /usr/sap/<SID>/DVEBMGS03/sec/SAFT_SAP_70_V1.PSE (client:    , key: 133103, len: 1311)

N  SsfPseLoad: Downloading file /usr/sap/<SID>/DVEBMGS03/sec/SAPSSLA.pse (client:    , key: 133226, len: 1073)

N  SsfPseLoad: Downloading file /usr/sap/<SID>/DVEBMGS03/sec/SAPSSLC.pse (client:    , key: 090335, len: 8426)

N  SsfPseLoad: Downloading file /usr/sap/<SID>/DVEBMGS03/sec/SAPSSLS.pse (client:    , key: 090616, len: 1346)

N  SsfPseLoad: Downloading file /usr/sap/<SID>/DVEBMGS03/sec/SAPSYS.pse (client:    , key: SYSPSE, len: 2314)

N  SsfPseLoad: Downloading file /usr/sap/<SID>/DVEBMGS03/sec/SAP_AGS_OLCNT_VERIFY.pse (client:    , key: 152117, len: 9570)

N  SsfPseLoad: ended (6 of 6 sucessfully loaded, 6 checked...

M  ThSchedInit: o.k.

I  MPI: dynamic quotas disabled.

I  MPI init: pipes=4000 buffers=6395 reserved=1918 quota=10%

M  CCMS: SemInMgt: Semaphore Management initialized by AlAttachShm_Doublestack.

M  CCMS: SemInit: Semaphore 38 initialized by AlAttachShm_Doublestack.

A  ***GENER* Trace switched on ***

A 

A  ---PXA-------------------------------------------

A  PXA INITIALIZATION

A  System page size: 4kb, total admin_size: 74060kb, dir_size: 24276kb.

A  Attached to PXA (address 700004270000000, size 972864K, 3 fragments of 299604K )

A  PXA allocated (address 700004270000000, size 972864K)

A  abap/pxa = shared unprotect gen_remote

A  PXA: checking structure sizes: 744|264|16

A  PXA INITIALIZATION FINISHED

A  ---PXA-------------------------------------------

A 

A  ATRA: pfclock execution time = 0

A 

A Tue Apr 15 21:22:51 2014

A  DFPAL: Use statically linked version of DFPAL

A  DFPAL: Execute DFP Instructions in hardware

A  abap/force_local_update_task=0

A  ABAP ShmAdm attached (addr=700003fcd6ae000 leng=125812736 end=700003fd4eaa000)

A  >> Shm MMADM area (addr=700003fcf31c000 leng=1476928 end=700003fcf484940)

A  >> Shm MMDAT area (addr=700003fcf485000 leng=94523392 end=700003fd4eaa000)

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

Y  dyWpInit

Y    ztta/dynpro_ara 800000

Y    ztta/cua_ara    500000

Y    ztta/diag_ara   350000

N  MskiInitLogonTicketCacheHandle: Logon Ticket cache pointer retrieved from shared memory.

N  MskiInitLogonTicketCacheHandle: Workprocess runs with Logon Ticket cache.

W  =================================================

W  === ipl_Init() called

W    ipl_Init(): wp task type is 5:SPO, skip initialization

W  === ipl_Init() returns 0, ITSPE_OK: OK

W  =================================================

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

N  SsfSapSecin: putenv(SECUDIR=/usr/sap/<SID>/DVEBMGS03/sec): ok

N  SsfSapSecin: PSE /usr/sap/<SID>/DVEBMGS03/sec/SAPSYS.pse found!

N 

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

N  === SSF INITIALIZATION:

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

N  ===...SSF library is /sapmnt/<SID>/exe/libsapcrypto.o .

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

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

N  ===...SECUDIR="/usr/sap/<SID>/DVEBMGS03/sec"

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

N  ===   CommonCryptoLib (SAPCRYPTOLIB) Version 8.4.15 pl40 (Feb 20 2014) MT-safe

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

N  SignInit: successfully obtained handle for Security Context cache

N  SPNegoInit: SPNego disabled ("spnego/enable" not set to 1)

M  JrfcVmcRegisterNativesDriver o.k.

M  WLM Tag '<SID>/SPO' successfully set for this process

E  EnqLockTableSizeCalculate: session quota = 100%

E  EnqLockTableAttach2: attach to lock table (size = 41943040)

E  EnqLockTableMapToLocalContext: enque/use_pfclock2 = FALSE

E  Replication is disabled

E  EnqId_Initialize: local EnqId initialization o.k.

A 

A Tue Apr 15 21:22:52 2014

A  AppServerTimeSync, checkLocalTime():

A    Initializing local WP variables:

A    zdate_LastLocalTime with 1397560972

A    zdate_LastLocalBias with 0

B  dbrda: Redirect database access is disabled via rsdb/rda profile parameter setting.

S  using action cache size 20 (prof=20)

S  creating spool memory service RSPO-ACTIONS at 70000423000a6a0

G 

G Tue Apr 15 21:22:54 2014

G  GetWritePermissionForShm( pLocation = 281, pEnforce = 0 )

G  RelWritePermissionForShm( pLocation = 277, pEnforce = 0 )

G 

G Tue Apr 15 21:22:55 2014

G  GetWritePermissionForShm( pLocation = 283, pEnforce = 0 )

G  RelWritePermissionForShm( pLocation = 277, pEnforce = 0 )

M 

M Tue Apr 15 21:22:56 2014

M  ***LOG Q0I=> NiPConnect2: 10.75.2.140:515: connect (79: Connection refused) [/bas/740_REL/src/base/ni/nixxi.cpp 3304]

M  *** ERROR => NiPConnect2: SiPeekPendConn failed for hdl 370/sock 61

    (SI_ECONN_REFUSE/79; I4; ST; 10.75.2.140:515) [nixxi.cpp    3304]

M  {root-id=534D0295168B0920E1008000A8FCE8C2}_{conn-id=00000000000000000000000000000000}_0

M 

M Tue Apr 15 21:22:57 2014

M  ***LOG Q0I=> NiPConnect2: 10.70.0.70:516: connect (79: Connection refused) [/bas/740_REL/src/base/ni/nixxi.cpp 3304]

M  *** ERROR => NiPConnect2: SiPeekPendConn failed for hdl 371/sock 61

    (SI_ECONN_REFUSE/79; I4; ST; 10.70.0.70:516) [nixxi.cpp    3304]

M  {root-id=534D0295168B0920E1008000A8FCE8C2}_{conn-id=00000000000000000000000000000000}_0

M  ***LOG Q0I=> NiPGetHostByName: 'cac533011d' not found: getaddrinfo [/bas/740_REL/src/base/ni/niuxi.c 1759]

M  ***LOG Q0I=> NiPGetHostByName: 'ot02' not found: getaddrinfo [/bas/740_REL/src/base/ni/niuxi.c 1759]

S  catch mode for rspo_rperf disabled

A  ***GENER* Trace switched off ***

E  Enqueue Info: enque/use_pfclock2 = FALSE

T 

T Tue Apr 15 21:23:51 2014

T  new memory block 115451140

M 

M Tue Apr 15 21:28:52 2014

M  ***LOG Q0I=> NiPConnect2: 10.75.2.140:515: connect (79: Connection refused) [/bas/740_REL/src/base/ni/nixxi.cpp 3304]

M  *** ERROR => NiPConnect2: SiPeekPendConn failed for hdl 372/sock 61

    (SI_ECONN_REFUSE/79; I4; ST; 10.75.2.140:515) [nixxi.cpp    3304]

M  {root-id=534D02C8168B0920E1008000A8FCE8C2}_{conn-id=00000000000000000000000000000000}_0

M 

M Tue Apr 15 21:28:53 2014

M  ***LOG Q0I=> NiPConnect2: 10.70.0.70:516: connect (79: Connection refused) [/bas/740_REL/src/base/ni/nixxi.cpp 3304]

M  *** ERROR => NiPConnect2: SiPeekPendConn failed for hdl 373/sock 61

    (SI_ECONN_REFUSE/79; I4; ST; 10.70.0.70:516) [nixxi.cpp    3304]

M  {root-id=534D02C8168B0920E1008000A8FCE8C2}_{conn-id=00000000000000000000000000000000}_0

M 

M Tue Apr 15 21:34:52 2014

M  ***LOG Q0I=> NiPConnect2: 10.75.2.140:515: connect (79: Connection refused) [/bas/740_REL/src/base/ni/nixxi.cpp 3304]

M  *** ERROR => NiPConnect2: SiPeekPendConn failed for hdl 373/sock 61

    (SI_ECONN_REFUSE/79; I4; ST; 10.75.2.140:515) [nixxi.cpp    3304]

M  {root-id=534D02F1168B0920E1008000A8FCE8C2}_{conn-id=00000000000000000000000000000000}_0

M 

M Tue Apr 15 21:34:53 2014

M  ***LOG Q0I=> NiPConnect2: 10.70.0.70:516: connect (79: Connection refused) [/bas/740_REL/src/base/ni/nixxi.cpp 3304]

M  *** ERROR => NiPConnect2: SiPeekPendConn failed for hdl 374/sock 61

    (SI_ECONN_REFUSE/79; I4; ST; 10.70.0.70:516) [nixxi.cpp    3304]

M  {root-id=534D02F1168B0920E1008000A8FCE8C2}_{conn-id=00000000000000000000000000000000}_0

M  ***LOG Q0I=> NiPGetHostByName: 'cac533011d' not found: getaddrinfo [/bas/740_REL/src/base/ni/niuxi.c 1759]

M  ***LOG Q0I=> NiPGetHostByName: 'ot02' not found: getaddrinfo [/bas/740_REL/src/base/ni/niuxi.c 1759]

[former_member188883]

Hi Pradeep,

Can you apply 741 kernel on your system and check the results.

Regards,

Deepak Kori

[tamil_arasan]

Thanks Deepak,

We supposed to run post processing steps in the upgrade process now., is it recommended to change the kernel at this stage?

Please clarify.

Thanks and regards,
Pradeep

[former_member188883]

Hi Pradeep,

As of now upgrade downtime has completed and kernel switch has already completed.

You may take backup and later update the kernel and check the results.

Hope this helps.

Regards,

Deepak Kori

[Reagan]

Check these SAP notes

1932555 - Dispatcher startup issue with SAP Kernel 740

1931675 - IP multicast configuration for dispatcher wakeup mechanism

I would first do a clean restart of the SAP system and see if that helps.

Regards

RB

[tamil_arasan]

Thanks RB,

I have done self test in the server whether multicasting is configured or not, Please find the following findings,

1)      Profile parameters not configured for IP multicasting:

rdisp/request_queue_mc_address_base

rdisp/request_queue_mc_address_offset

2)      Command niping –t should give the following result as per the note however we didn’t get the expected result.

Expected result: MulticastLocalCheck (NiDgHdlSendTo UDP, <Base IP>) rc = 0

We didn’t get the above line in the output.

3)      Command ifconfig –a

Result: multicasting is enabled in our system 

4)  Command netstat -rn gave the expected results.

we didn't get  " Yes, the IPSec package is installed" in the output for the command lslpp -al bos.net.ipsec.*

ksh: ipsecstat: cannot execute

ksh: lsfilt: cannot execute

Kidly help me to narrow down the issue.

Thanks and regards,

Pradeep