Error in phase MAIN_SHADOW/START_SHDI_FIRST (Upgrade EHP)

[joo_migueldimas]

Hello to all,

(This plataform is an IBM DB2 for i5/OS)

I´m performing a Enhancement Package upgrade in our sap system from EHP3 to EHP5, but I´m stuck in phase MAIN_SHADOW/START_SHDI_FIRST (STARTS THE SHADOW SYSTEM). This error show the following message:

severe error(s) occured in phase MAIN_SHADOW/START_SHDI_FIRST!
Last error code set: Shadow instance couldn´t be started, check 'STARTSFI.LOG' and 'DEVTRACE.LOG'

So, I will post here that log files.

STARTFI.LOG:

1 ETQ200 Executing actual phase 'MAIN_SHADOW/START_SHDI_FIRST'.
1 ETQ399 Phase arguments:
2 ETQ399 Arg[0] = 'DEVTRACE.LOG'
4 ETQ399 Set environment for shadow connect:
4 ETQ399 Set RFC variables for shadow connect:
4 ETQ399 System-nr = '01', GwService = 'sapgw01'
4 ETQ380 computing toolpath for request "TP_SHADOW_CONNECT"
4 ETQ381 request "TP_SHADOW_CONNECT" means "tp needs to connect to shadow system"
4 ETQ382 translates to group "R3UP_TOOL_GROUP_NEW"
4 ETQ383 translates to path "exe"
4 ETQ383 translates to path "exe"
4 ETQ399 Set tool parameters for shadow connect:
4 ETQ399   default TPPARAM: SHADOW.TPP
4 ETQ380 computing toolpath for request "TP_ALWAYS_NEW"
4 ETQ381 request "TP_ALWAYS_NEW" means "always tp from DIR_PUT/exe, for phase KX_SWITCH"
4 ETQ382 translates to group "R3UP_TOOL_GROUP_NEW"
4 ETQ383 translates to path "exe"
4 ETQ383 translates to path "exe"
2 ETQ399 Starting shadow instance
4 ETQ359 RFC Login to: System="DEV", Nr="01", GwHost="SAPDEV", GwService="sapgw01"
2 ETQ231 RFC Login failed
4 ETQ359 RFC Login to: System="DEV", Nr="01", GwHost="SAPDEV", GwService="sapgw01"
2 ETQ231 RFC Login failed
2 ETQ399 Stopping shadow instance
4 ETQ359 RFC Login to: System="DEV", Nr="01", GwHost="SAPDEV", GwService="sapgw01"
2 ETQ231 RFC Login failed
4 ETQ359 RFC Login to: System="DEV", Nr="01", GwHost="SAPDEV", GwService="sapgw01"
2 ETQ231 RFC Login failed
2 ETQ353 Starting system
3 ETQ399 Executing command: 'startsap  SID(DEV) INSTANCE(01) PROFILE('/usr/sap/DEV/EHPI/abap/DEV/SYS/profile/START_DVEBMGS01_SAPDEV') TYPE(*SHD)'.
2 ETQ370 starting test RFC
...
...
4 ETQ359 RFC Login to: System="DEV", Nr="01", GwHost="SAPDEV", GwService="sapgw01"
2 ETQ231 RFC Login failed
2WETQ372 test RFC failed, rc="-1"
2EETQ399 Starting shadow instance failed
2EETQ399 Test RFC failed finally

DEVTRACE.LOG:

....
DpShMCreate: sizeof(j2ee_adm)	3952
DpShMCreate: SHM_DP_ADM_KEY		(addr: 700000060000000, size: 6379664)
DpShMCreate: allocated sys_adm at 700000060000010
DpShMCreate: allocated wp_adm_list at 700000060002ff0
DpShMCreate: allocated wp_adm at 7000000600031e0
DpShMCreate: allocated tm_adm_list at 7000000600104b0
DpShMCreate: allocated tm_adm at 700000060010500
DpShMCreate: allocated appc_ca_adm at 700000060562e20
DpShMCreate: allocated comm_adm at 700000060572830
DpShMCreate: system runs without slock table
DpShMCreate: system runs without file table
DpShMCreate: allocated vmc_adm_list at 7000000606011d0
DpShMCreate: system runs without vmc_adm
DpShMCreate: allocated gw_adm at 700000060601280
DpShMCreate: allocated j2ee_adm at 7000000606012c0
DpShMCreate: allocated ca_info at 700000060602240
DpCommAttachTable: attached comm table (header=700000060572830/ft=700000060572840)
MtxInit: -2 0 0
DpRqQInit: use protect_queue / slots_per_queue 0 / 2001 from sys_adm

Mon Sep  5 22:48:58 2011
GwISigint: received SIGINT (2), start shutdown phase
***LOG S30=> GwStopGateway, gateway stopped () [gwxxrd.c     12995]

Can you help me please, how to solve this error?

Best regards,

João Dimas - Portugal

[Former Member · Accepted solution]

Hi,

Could you also let us know if there are errors in the dev_disp and dev_w* logs of the shadow instance?

Should be in /usr/sap/DEV/EHPI/abap/DEV/DVEBMGS01/work/

The logs should have more information about the startup/login errors.

Regards,

Srikishan

[joo_migueldimas · Accepted solution]

Hello Srikishan D,

The dev_disp:

...
DpShMCreate: allocated vmc_adm_list at 7000000506011d0
DpShMCreate: system runs without vmc_adm
DpShMCreate: allocated gw_adm at 700000050601280
DpShMCreate: allocated j2ee_adm at 7000000506012c0
DpShMCreate: allocated ca_info at 700000050602240
DpShMCreate: allocated wall_adm at 7000000506022d0
DpCommAttachTable: attached comm table (header=700000050572830/ft=700000050572840)
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
<ES> client 0 initializing ....
<ES> InitFreeList
<ES> block size is 4096 kByte.

Mon Sep  5 22:48:45 2011
Using implementation std
EsStdUnamFileMapInit: ES base = 0x7000000a0000000
EsStdInit: Extended Memory 4096 MB allocated
<ES> 1023 blocks reserved for free list.
ES initialized.
mm.dump: set maximum dump mem to 96 MB
DpVmcSetActive: set vmc state DP_VMC_NOT_ACTIVE
MPI: dynamic quotas disabled.
MPI init: pipes=4000 buffers=1279 reserved=383 quota=10% 
*** WARNING => System running without ICM - check rdisp/start_icman [dpxxdisp.c   13097]

Mon Sep  5 22:48:51 2011
rdisp/http_min_wait_dia_wp : 1 -> 1
***LOG CPS=> DpLoopInit, ICU ( 3.4 3.4 4.1) [dpxxdisp.c   1673]
***LOG Q0I=> NiIWrite: 192.168.1.142:3601: writev (32: Broken pipe) [nixxi.cpp 4604]
*** ERROR => NiIWrite: SiSendV failed for hdl 17/sock 10
    (SI_ECONN_BROKEN/32; UD; ST; 192.168.1.142:3601) [nixxi.cpp    4604]
*** ERROR => MsINiWrite: NiBufSend (rc=NIECONN_BROKEN) [msxxi.c      2776]
*** ERROR => MsIDetach: MsINiWrite (rc=MSENILAYER) [msxxi.c      1302]

*****************************************************************************
*
*  LOCATION    SAP-Dispatcher SAPDEV_DEV_01 on host SAPDEV.LUSITECA.PT
*  ERROR       mserrno received (MSEACCESSDENIED)
*
*  TIME        Mon Sep  5 22:48:51 2011
*  RELEASE     720
*  COMPONENT   MS (message handling interface)
*  VERSION     4
*  RC          -24
*  MODULE      msxxi.c
*  LINE        962
*  COUNTER     7
*
*****************************************************************************

*** ERROR => not allowed to connect to message server via port 3601 [dpxxdisp.c   12284]
*** ERROR => Please check your configuration (profile parameter rdisp/msserv_internal) [dpxxdisp.c   12285]
DpHalt: shutdown server >SAPDEV_DEV_01                           < (normal)
DpHalt: stop work processes

Mon Sep  5 22:48:58 2011
DpHalt: stop gateway
DpHalt: terminate gui connections
DpHalt: wait for end of work processes
DpHalt: wait for end of gateway
DpHalt: waiting for termination of gateway ...

Mon Sep  5 22:48:59 2011
DpHalt: not attached to the message server
DpHalt: cleanup EM
DpHalt: cleanup event management
DpHalt: cleanup shared memory/semaphores
DpCleanupSharedResources: removing request queue
***LOG Q05=> DpHalt, DpHalt ( 9084) [dpxxdisp.c   11309]
DpHalt: *** shutdown completed - server stopped ***

This message has continuation...

[Former Member · Accepted solution]

• ERROR => not allowed to connect to message server via port 3601 [dpxxdisp.c 12284]

• ERROR => Please check your configuration (profile parameter rdisp/msserv_internal) [d

I hope parameter is correct, Please confirm if the port is free or not.

[joo_migueldimas · Accepted solution]

... continuation...

The dev_w0:

...
M Mon Sep  5 22:48:48 2011
M  ThInit: running on host SAPDEV
M  calling db_connect ...
B  Loading DB library '/usr/sap/DEV/EHPI/abap/exe/dbdb4slib.o' ...
B  Library '/usr/sap/DEV/EHPI/abap/exe/dbdb4slib.o' loaded
B  Version of '/usr/sap/DEV/EHPI/abap/exe/dbdb4slib.o' is "720.00", patchlevel (0.98)
C  DB4 SQL Reparse Activated
C  *** ERROR => dbs/db4/schema contains wrong schema name SAPR3.
 [dbsldb4.cpp  7094]
C  Error is ignored. Schema R3DEVDATA is used.
C  IBM i 7.1 - XDN Default
C  XDN-Port: Assuming 9600 + sapmsDEV mod 100 = 9600
C  as4IsHostLocal: SAPDBHOST 'SAPDEV' is local
C  R3INLPGM: RmtExeLib from /usr/sap/DEV/EHPI/abap/exe/DBSLDB4RMT
C  R3INLPGM: RmtExeLib is SAPDEVUPG
C  DBSLENCWT: rc=0, msg=CPF9897 CONCURRENT WRITE IS ENABLED.                                    
C  QXDARECVR PTF Level is: SI37200   
C  
C Mon Sep  5 22:48:49 2011
C  DbSl/DB codepage check: OK - (Unicode).
C  Checking journal settings for QSQJRN    /R3DEVDATA : OK
C  === Central DB connect successfull! ===
C  === Connection settings ===
C  connected               = TRUE
C  con_hdl                 = 0
C  db_handle               = 1
C  dbhost                  = SAPDEV
C  dbhostport              = 9600
C  rdbname                 =                   
C  dblib                   = R3DEVSHD
C  r3sysle_changed         = TRUE
C  query_compl_reval       = O
C  dbconnecttype           = L
C  user                    = DEV01     
C  qaqqinilib              = Default (QUSRSYS)
C  dbjobname               = WP00      
C  dbjobuser               = DEV01     
C  dbjobno                 = 012091
C  rmtexelib               = SAPDEVUPG
C  parallel_alter_tables   = *OFF
C  ===========================
C  Query options file QUSRSYS/QAQQINI not found.
C  -----------------------------------------------------------------------------
C  ----- DbSl EGO Structure
C  -----------------------------------------------------------------------------
C     SAPSYSTEMNAME               = DEV
C     Character encoding          = UNICODE
C     process class               = dialog process
C     workprocess id              = 0
C     local host                  = SAPDEV
C     dbhost                      = SAPDEV
C     dbhostport                  = 9600
C     rdbname                     =                   
C     dbname                      = DEVSAPDEV
C     dblib                       = R3DEVSHD
C     application server          = DVEBMGS01
C     driver                      = DBSLDirectDrive
C     Connect type                = LOCAL
C     pid                         = 9088
C     wpjobname                   = WP00
C     wpjobuser                   = DEV01
C     wpjobno                     = 012091
C     DB2/400 vers. appl. server  = PASE 7.1
C     DB2/400 vers. DB server     = V7R1
C     da_cache_size               = 100
C     dbsl_buffersize             = 131072
C     reopen                      = ON
C     timeout_retry               = 3
C     alter_table_timeout_retry   = 3
C     ODP threshold               = 800
C     ODP commit thresh.          = 810
C     ODP open thresh.            = 850
C     QAQQINI library             = Default (QUSRSYS)
C     Alternate QAQQINI library   = Not specified
C     use_lobs_for_long           = ON
C     use_lobs_for_short          = OFF
C     single_execution_threshold  = 2000
C     single_execution_reuse      = OFF
C     keep_tmp_SQLpkgs            = OFF
...
M Mon Sep  5 22:48:54 2011
M  SecAudit(rsauinit): Start init of Security Audit Log for first wp.
M  in_ThErrHandle: 1
M  ThIErrHandle: new stat of W0 is WP_SHUTDOWN    
M  ThIErrHandle: I'm during shutdown
M  PfStatDisconnect: disconnect statistics
M  ThIErrHandle: entering ThSetStatError
M  ThShutDownServer: shutdown server
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 9088) [dpuxtool.c   327]

[joo_migueldimas · Accepted solution]

Hello Database&SAP,

For that I checked the service table in iSeries with command WRKSRVTBLE:

Opt  Service                                  Port  Protocol
                                                            
       sapmsDEV                                 3600  tcp     
       sapmsSHDDEV                              3601  tcp

And regarding parameter I only see the following parameter in DEFAULT.PFL of main instance (00) but not in shadow instance profiles:

rdisp/msserv_internal = 3900

Thank you,

JDimas

[sunny_pahuja2 · Accepted solution]

Hi,

Check SAP Note 525677 - Problems when starting shadow instance..

Thanks

Sunny

[joo_migueldimas · Accepted solution]

Hello Sunny and all the others,

This error was solved...

What I did was, first I searched for the following error in DEVTRACE.LOG file:

MsSLoginClient: client SAPDEV_DEV_01 (127.0.0.1) is not in acl list, access denied

I read one SDN thread () and in there is suggested to read the sap note 822296 - Additional info: Upgrade to SAP NW 2004s AS ABAP (iSeries). In that sap note is mentioned:

------------------------< D027190 JUN/26/2006 >--------------------
START_SHDI_FIRST phase

Symptom: The shadow system does not start. The following message
is issued in the dev_ms developer trace of the shadow instance:

client ... is not in acl list, access denied
...

And this is the exactly the same error that it shown to me!

I followed that solution with success!

But I don´t know why this error is not mentioned in sap note 525677 - Problems when starting shadow instance..

In my case I´m performing an upgrade to Enhacement Package (EHP5), and not an upgrade to SAP NW 2004s AS ABAP where this error is described and where I found the solution, I think this should also be in note 525677!

Best regards,

João Dimas - Portugal

[Former Member]

Hi,

Hi,

" Be sure that the name of the instance profile for the primary application server instance corresponds to SAP conventions before start the upgrade, that is, ensure that the name has the form <SID>_DVEBMGS< nn>_<host>. The referencing in the start profile must also be modified to include any changes that have been made. Any differences mean that it will not be possible to convert the name of the instance profile in the copy of the start profile for the shadow instance. As a result, you cannot start the shadow instance in the phase START_SHDI_FIRST.

After you execute the preprocessing unit, check whether the entries in the start profile of the shadow instance are consistent with the name of the associated instance profile. Shadow instance profiles are available in directory of upgrade. The default is /usr/sap/<SID>/upg/abap/SID/SYS/profile."

For information regarding this problem please see the following SAP note..

Note 1487909 - Upgrade to SAP NetWeaver 7.30: IBM DB2 for i

Note 525677 - Problems when starting shadow instance

Regards

Bhuban

[Former Member]

In starting the shadow instance it takes instance as 01, so i suppose yours is a single stack system.

1.)could you please check your gateway is running? t-code smgw or OS process.

if its not running, please start it & hit retry on the ehpi. Else please paste the dev_rd trace here.

ps: the trace from work dir in /usr/sap/<sid>/EHPI/....work

2.)Also check sappfpar for memory errors, correct them & restart the instance.