WebAS 620 / CRM 4.0 system not starting up after patch
I have recently built a CRM 4.0 system on WebAS 620 (APAB stack only) and it fails to start up after patching to:
SAP_BASIS - 0056
SAP_ABA - 0056
BBPCRM - 0009
PI_BASIS - 0010
Kernel - 640_87 (Aug 21 2005 23:40:31)
The only other change made to the system was an attempt to add the "login/system_client", which was removed from the Default profile when the system didn't start up.
This system is running on Windows Server 2003 SP1 and the Central And Database instances are running on a single 2 node cluster. I have moved all resources to one node to rule out a networking issue.
When I start the SAP service from Cluster Administrator, it runs for about 3 seconds then fails. I have increased the trace level to 3 (rdisp/TRACE = 3) but still cannot figure out the root cause of the problem. Below are the trace files:
SAPSTART.TRC
-
trc file: "dev_sapservice", trc level: 3
-
SOLAR-TEST\slrcluster is starting R/3 System at 2006/01/23 12:12:25
SAP-R/3-Startup Program
Starting at 2006/01/23 12:12:25
Startup Profile: "D:\usr\sap\CRM\SYS\profile\START_DVEBMGS00_p-crm-sap"
Starting Programs
(2912) CreateProcess: D:\usr\sap\CRM\SYS\exe\run\msg_server.exe pf=D:\usr\sap\CRM\SYS\profile\CRM_DVEBMGS00_p-crm-sap
(5176) CreateProcess: D:\usr\sap\CRM\SYS\exe\run\disp+work.exe pf=D:\usr\sap\CRM\SYS\profile\CRM_DVEBMGS00_p-crm-sap
(4348) CreateProcess: D:\usr\sap\CRM\DVEBMGS00\igs\bin\igswd.exe -dir=D:\usr\sap\CRM\DVEBMGS00\igs -mode=all -sysnam
(5256) Parent Shutdown at 2006/01/23 12:12:36
kill created process
(5256) kill(SIGINT 4348) failed.
(5256) kill(SIGINT 5176) succeeded.
(5256) kill(SIGINT 2912) succeeded.
DEV_MS
-
trc file: "dev_ms", trc level: 3, release: "640"
-
...
[Thr 4124] LgMsGetList: switch to internal mode (00407EE8=MsSGetList)
[Thr 4124] LgMsGetSnc: switch to internal mode (00407CB7=MsSGetSnc)
[Thr 4124] LgMsSetMsChkVhost: switch to internal mode (00407DBA=MsSChkVhost)
[Thr 4124] LgMsSetMsChkVhost2: switch to internal mode (0040AE77=MsSChkVhost2)
[Thr 4124] LgMsGetNameByIpadr: switch to internal mode (0040AFC4=MsSGetNameByIpadr)
[Thr 4124] *** I listen to port sapmsCRM (3600) ***
[Thr 4124] *** HTTP LISTEN ***
[Thr 4124] *** HTTPS INIT ***
[Thr 4124] *** HTTP port 8100 state LISTEN ***
[Thr 4124] CUSTOMER KEY: >XXXXXXXXXXXX<
[Thr 4124] START of msg_server main loop
[Thr 4124] *********** MS LOOP ***********
[Thr 4124] NiBufSelect: Preprocessing...
[Thr 4124] NiISelect: timeout 20000 ms
[Thr 4124] NiISelect: maximum fd=1789
[Thr 4124] NiISelect: fds in read-mask: [Thr 4124] 1784 [Thr 4124] 1788 [Thr 4124]
[Thr 4124] NiISelect: fds in write-mask: [Thr 4124]
[Thr 4124] Mon Jan 23 12:12:35 2006
[Thr 4124] NiBufSelect: Postprocessing...
[Thr 4124] NiIPeekListen: peek successful for hdl 1 / socket 1788 / socket -1
[Thr 4124] SetQoS not possible, no QoS Provider available
[Thr 4124] NiIInitSocket: set default settings for socket 1772
[Thr 4124] NiIAccept: connect from: host xxx.xxx.xxx.18, port 04.C7/1223, fam 2 (low adr..high adr)
[Thr 4124] NiCreateHandle: state hdl 3 / socket 1772 NI_INITIAL
[Thr 4124] nilh-localCheck: using local address list
[Thr 4124] nilh-localCheck: matched local address: xxx.xxx.xxx.18
[Thr 4124] NiIAccept: took local port 0E.10/3600
[Thr 4124] NiSetStat: state hdl 3 NI_CONNECTED
[Thr 4124] NiPBlockMode: set socket 1772 to NONBLOCK mode
[Thr 4124] NiIBlockMode: switch off block-mode for hdl 3 / socket 1772
[Thr 4124] NiBufHdlInit: BufInit for hdl 3
[Thr 4124] NiBufSetStat: bufstat of hdl 3 changed from OFF to OK
[Thr 4124] NiBufSelect: returning 1 clients
[Thr 4124] NiSelNext: returning hdl 1, --c, 00000000, rest 0 entries (011B93E8)
[Thr 4124] MsSConnect: CONNECT request received (hdl=1)
[Thr 4124] NiBufSetParam: Setting alloc function for hdl 3 to 004084A1
[Thr 4124] MsSConnect: open hdl 3
[Thr 4124] MsSAddClient: INTERNAL client C0 (xxx.xxx.xxx.18) is in stat CONNECTED
[Thr 4124] MsSAddClient: 1 client connected
[Thr 4124] NiSelSet: hdl 3, r-, 011C1508
[Thr 4124] *********** MS LOOP ***********
[Thr 4124] NiBufSelect: Preprocessing...
[Thr 4124] NiISelect: timeout 20000 ms
[Thr 4124] NiISelect: maximum fd=1789
[Thr 4124] NiISelect: fds in read-mask: [Thr 4124] 1772 [Thr 4124] 1784 [Thr 4124] 1788 [Thr 4124]
[Thr 4124] NiISelect: fds in write-mask: [Thr 4124]
[Thr 4124] NiBufSelect: Postprocessing...
[Thr 4124] NiBufIAlloc: malloc NIBUF-IN, to 32110 bytes
[Thr 4124] MsSBufAlloc: allocated 1. buffer at 012B4808
[Thr 4124] NiIRead: read 110, 1 packs, MESG_IO, hdl 3, data complete
[Thr 4124] NiBufIn: NIBUF len=110
[Thr 4124] NiBufIn: Packet complete for hdl 3
[Thr 4124] NiBufSelect: returning 1 clients
[Thr 4124] NiSelNext: returning hdl 3, r--, 011C1508, rest 0 entries (011B9408)
[Thr 4124]
NiBufReceive starting
[Thr 4124] -IN-- client 0 name - len 110
[Thr 4124] -IN-- key - iflag MS_LOGIN_2
[Thr 4124] -IN-- > name - flag 0
[Thr 4124] MsSClientHandle: client name = xxx.xxx.xxx.18
[Thr 4124] MsSClientHandle: set buffer len to 32110
[Thr 4124] C0 (xxx.xxx.xxx.18) is in stat LOGGED_IN (WAS domain)
[Thr 4124] NiBufWrite starting
[Thr 4124] NiIWrite: write 110, 1 packs, MESG_IO, hdl 3, data complete
[Thr 4124] -OUT- client 0 name - errno MSOP_OK
[Thr 4124] -OUT- key -
[Thr 4124] MsSBufFree: 012B4808 to cache, cache count=1
[Thr 4124] *********** MS LOOP ***********
[Thr 4124] NiBufSelect: Preprocessing...
[Thr 4124] NiISelect: timeout 20000 ms
[Thr 4124] NiISelect: maximum fd=1789
[Thr 4124] NiISelect: fds in read-mask: [Thr 4124] 1772 [Thr 4124] 1784 [Thr 4124] 1788 [Thr 4124]
[Thr 4124] NiISelect: fds in write-mask: [Thr 4124]
[Thr 4124] NiBufSelect: Postprocessing...
[Thr 4124] MsSBufAlloc: returning 012B4808, cache count = 0
[Thr 4124] NiIRead: read 114, 1 packs, MESG_IO, hdl 3, data complete
[Thr 4124] NiBufIn: NIBUF len=114
[Thr 4124] NiBufIn: Packet complete for hdl 3
[Thr 4124] NiBufSelect: returning 1 clients
[Thr 4124] NiSelNext: returning hdl 3, r--, 011C1508, rest 0 entries (011B9408)
[Thr 4124]
NiBufReceive starting
[Thr 4124] -IN-- client 0 name - len 114
[Thr 4124] -IN-- key - iflag MS_SEND_NAME
[Thr 4124] -IN-- > name MSG_SERVER flag MS_REQUEST
[Thr 4124] MsSProcOpcode: processing MS_SERVER_LST ...
[Thr 4124] client C0 (xxx.xxx.xxx.18) requests a list of all connected clients
[Thr 4124] MsSConv_Client_L2: convert -
[Thr 4124] MsSRetClientList: append list of all connected clients (1)
[Thr 4124] NiBufWrite starting
[Thr 4124] NiIWrite: write 229, 1 packs, MESG_IO, hdl 3, data complete
[Thr 4124] -OUT- client 0 name - errno MSOP_OK
[Thr 4124] -OUT- key -
[Thr 4124] MsSBufFree: 012B4808 to cache, cache count=1
[Thr 4124] MsSProcOpcode: MS_SERVER_LST (version=102) ok
[Thr 4124] *********** MS LOOP ***********
[Thr 4124] NiBufSelect: Preprocessing...
[Thr 4124] NiISelect: timeout 20000 ms
[Thr 4124] NiISelect: maximum fd=1789
[Thr 4124] NiISelect: fds in read-mask: [Thr 4124] 1772 [Thr 4124] 1784 [Thr 4124] 1788 [Thr 4124]
[Thr 4124] NiISelect: fds in write-mask: [Thr 4124]
[Thr 4124] Mon Jan 23 12:12:36 2006
[Thr 4124] NiBufSelect: Postprocessing...
[Thr 4124] MsSBufAlloc: returning 012B4808, cache count = 0
[Thr 4124] NiIRead: read 114, 1 packs, MESG_IO, hdl 3, data complete
[Thr 4124] NiBufIn: NIBUF len=114
[Thr 4124] NiBufIn: Packet complete for hdl 3
[Thr 4124] NiBufSelect: returning 1 clients
[Thr 4124] NiSelNext: returning hdl 3, r--, 011C1508, rest 0 entries (011B9408)
[Thr 4124]
NiBufReceive starting
[Thr 4124] -IN-- client 0 name - len 114
[Thr 4124] -IN-- key - iflag MS_SEND_NAME
[Thr 4124] -IN-- > name MSG_SERVER flag MS_REQUEST
[Thr 4124] MsSProcOpcode: processing MS_SERVER_LST ...
[Thr 4124] client C0 (xxx.xxx.xxx.18) requests a list of all connected clients
[Thr 4124] MsSConv_Client_L2: convert -
[Thr 4124] MsSRetClientList: append list of all connected clients (1)
[Thr 4124] NiBufWrite starting
[Thr 4124] NiIWrite: write 229, 1 packs, MESG_IO, hdl 3, data complete
[Thr 4124] -OUT- client 0 name - errno MSOP_OK
[Thr 4124] -OUT- key -
[Thr 4124] MsSBufFree: 012B4808 to cache, cache count=1
[Thr 4124] MsSProcOpcode: MS_SERVER_LST (version=102) ok
[Thr 4124] *********** MS LOOP ***********
[Thr 4124] NiBufSelect: Preprocessing...
[Thr 4124] NiISelect: timeout 20000 ms
[Thr 4124] NiISelect: maximum fd=1789
[Thr 4124] NiISelect: fds in read-mask: [Thr 4124] 1772 [Thr 4124] 1784 [Thr 4124] 1788 [Thr 4124]
[Thr 4124] NiISelect: fds in write-mask: [Thr 4124]
[Thr 4124] NiBufSelect: Postprocessing...
[Thr 4124] MsSBufAlloc: returning 012B4808, cache count = 0
[Thr 4124] NiIRead: read 114, 1 packs, MESG_IO, hdl 3, data complete
[Thr 4124] NiBufIn: NIBUF len=114
[Thr 4124] NiBufIn: Packet complete for hdl 3
[Thr 4124] NiBufSelect: returning 1 clients
[Thr 4124] NiSelNext: returning hdl 3, r--, 011C1508, rest 0 entries (011B9408)
[Thr 4124]
NiBufReceive starting
[Thr 4124] -IN-- client 0 name - len 114
[Thr 4124] -IN-- key - iflag MS_SEND_NAME
[Thr 4124] -IN-- > name MSG_SERVER flag MS_REQUEST
[Thr 4124] MsSProcOpcode: processing MS_SERVER_LST ...
[Thr 4124] client C0 (xxx.xxx.xxx.18) requests a list of all connected clients
[Thr 4124] MsSConv_Client_L2: convert -
[Thr 4124] MsSRetClientList: append list of all connected clients (1)
[Thr 4124] NiBufWrite starting
[Thr 4124] NiIWrite: write 229, 1 packs, MESG_IO, hdl 3, data complete
[Thr 4124] -OUT- client 0 name - errno MSOP_OK
[Thr 4124] -OUT- key -
[Thr 4124] MsSBufFree: 012B4808 to cache, cache count=1
[Thr 4124] MsSProcOpcode: MS_SERVER_LST (version=102) ok
[Thr 4124] *********** MS LOOP ***********
[Thr 4124] NiBufSelect: Preprocessing...
[Thr 4124] NiISelect: timeout 20000 ms
[Thr 4124] NiISelect: maximum fd=1789
[Thr 4124] NiISelect: fds in read-mask: [Thr 4124] 1772 [Thr 4124] 1784 [Thr 4124] 1788 [Thr 4124]
[Thr 4124] NiISelect: fds in write-mask: [Thr 4124]
[Thr 5476] Pipe read request: 2 anz: 64
[Thr 5476] Signal handling in the signal thread (signal 2)
[Thr 5476] MsSExit: received SIGINT (2)
[Thr 5476] ***LOG Q02=> MsSHalt, MSStop (Msg Server 2912) [msxxserv.c 5352]
[Thr 5476] Good Bye .....
DEV_DISP
-
trc file: "dev_disp", trc level: 3, release: "640"
-
kernel runs with dp version 129(ext=102) (@(#) DPLIB-INT-VERSION-129)
length of sys_adm_ext is 312 bytes
command line arg 0: D:\usr\sap\CRM\SYS\exe\run\disp+work.exe
command line arg 1: pf=D:\usr\sap\CRM\SYS\profile\CRM_DVEBMGS00_p-crm-sap
load shared library (dboraslib.dll), hdl 0
using "D:\usr\sap\CRM\SYS\exe\run\dboraslib.dll"
load shared func (DbSlExpFuns) from dboraslib.dll
load shared func (dsql_db_init) from dboraslib.dll
load shared func (dbdd_exp_funs) from dboraslib.dll
sysno 00
sid CRM
systemid 560 (PC with Windows NT)
relno 6400
patchlevel 0
patchno 87
intno 20020600
make: multithreaded, ASCII
pid 5176
***LOG Q00=> DpSapEnvInit, DPStart (00 5176) [dpxxdisp.c 1098]
ShmProtect( 5, 3 )
SigIInit: ok (whoami=1)
Thread handle for mainthread created
SigIRegisterRoutine: handler for signal 11 installed (SigISegv)
Pipe created:
.\pipe\SAP5176
SigIInit: Create Message Thread
SigIRegisterExitRoutine: exithandler installed (DpHalt)
SigIRegisterTerminateRoutine: terminatehandler installed (DpHalt)
shared lib "dw_xml.dll" version 87 successfully loaded
shared lib "dw_xtc.dll" version 87 successfully loaded
shared lib "dw_stl.dll" version 87 successfully loaded
shared lib "dw_gui.dll" version 87 successfully loaded
dp_loc_queue_max_blk: 40000
mshost: >p-crm-sap<
msserv: >sapmsCRM<
dp_bufreftime: 120 sec
dp_btctime: 60 sec
dp_autoabaptime: 300 sec
dp_autothtime: 60 sec
dp_calldelayed_time: 60 sec
dp_noptime: 0 sec
dp_startup_time: 20
dp_keepalive: 1200 sec
dp_keepalive_timeout: 60 sec
dp_ms_keepalive: 60 sec
dp_ms_keepalive_timeout: 300 sec
switch off dp-keep-alive for old temus
dp_gui_auto_logout: 0 sec
dp_spoolalrm: 60 sec
dp_softcancel_timeout: 5 sec
softsignal_delay: 0
rdisp/wp_restart_interval : 300 sec
DpISetTrcLog: switched off trace logging
dp_rfc_check_active: 1
dp_rfc_check_all_rfcs: 0
dp_http_check: 1
nihsl-getServNo: got servicename 'sapdp00' from operation system
SN='sapdp00'; Port=0C.80/3200; PC=tcp
nihsi-getServNo: servicename 'sapdp00' = port 0C.80/3200
nihsl-getServNo: got servicename 'sapgw00' from operation system
SN='sapgw00'; Port=0C.E4/3300; PC=tcp
nihsi-getServNo: servicename 'sapgw00' = port 0C.E4/3300
NiIMyHostName: hostname = 'p-crm-sapa'
nihsl-getHostAddr: got hostname 'p-slr-CRMa' from operation system
HN='p-crm-sapa.solar-test.com'; Add[0]=xxx.xxx.xxx.15; Add[1]=xxx.xxx.xxx.100; Add[2]=xxx.xxx.xxx.19; Add[3]=xxx.xxx.xxx.17; Add[4]=xxx.xxx.xxx.18
nihsi-getHostAddr: hostname 'p-slr-CRMa' = addr xxx.xxx.xxx.15
nihsl-getHostName: got address xxx.xxx.xxx.15 from operation system
HN='p-crm-sapa'; Add[0]=xxx.xxx.xxx.15
nihsi-getHostName: addr xxx.xxx.xxx.15 = hostname 'p-crm-sapa' (fq)
Mon Jan 23 12:12:36 2006
Pipe read request: 2 anz: 64
Signal handling in the signal thread (signal 2)
call exithandler DpHalt(TRUE)
Shutdown server ...
DpJ2eeDisableRestart
Switch off Shared memory profiling
ShmProtect( 57, 3 )
ShmProtect(SHM_PROFILE, SHM_PROT_RW
ShmProtect( 57, 1 )
ShmProtect(SHM_PROFILE, SHM_PROT_RD
detach from message server
Good Bye .....
If you have any idea what the issue might be, please let me know. It's driving me nuts!
Thanks.
Andrew