J2EE StartUp Problem, URGENT.

[Former Member]

Hi all!

I'm having a problem since friday with the J2EE Engine Startup. The problem is that MMC says me that the server is running but i can access to the server by anyway. The developer trace of the jcontrol process is:

[Thr 2968] Tue Aug 09 13:59:50 2005

[Thr 2968] JControlICheckProcessList: process server0 started (PID:1544)

**********************************************************************

JStartupStartJLaunch: program = C:\usr\sap\J2E\JC00/j2ee/os_libs/jlaunch.exe

-> arg[00] = C:\usr\sap\J2E\JC00/j2ee/os_libs/jlaunch.exe

-> arg[01] = pf=C:\usr\sap\J2E\SYS\profile\J2E_JC00_toshiba-user

-> arg[02] = -DSAPINFO=J2E_00_sdm

-> arg[03] = -file=C:\usr\sap\J2E\JC00\SDM\program\config\sdm_jstartup.properties

-> arg[04] = -nodeName=sdm

-> arg[05] = -nodeId=2

-> arg[06] = -syncSem=JSTARTUP_WAIT_ON_2964

-> arg[07] = -jvmOutFile=C:\usr\sap\J2E\JC00\work\jvm_sdm.out

-> arg[08] = -stdOutFile=C:\usr\sap\J2E\JC00\work\std_sdm.out

-> arg[09] = -locOutFile=C:\usr\sap\J2E\JC00\work\dev_sdm

-> arg[10] = -mode=JCONTROL

-> arg[11] = pf=C:\usr\sap\J2E\SYS\profile\J2E_JC00_toshiba-user

-> lib path = PATH=C:\j2sdk1.4.2_08\jre\bin\server;C:\j2sdk1.4.2_08\jre\bin;C:\oracle\WAS\92\bin;C:\oracle\WAS\92\jre\1.4.2\bin\client;C:\oracle\WAS\92\jre\1.4.2\bin;C:\Program Files\Oracle\jre\1.3.1\bin;C:\Program Files\Oracle\jre\1.1.8\bin;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\j2sdk1.4.2_08\bin;C:\oracle\WAS\92\Appache\perl\5.00503\bin\MSWin32-x86;C:\usr\sap\J2E\SCS01\exe;C:\usr\sap\J2E\JC00\exe;C:\usr\sap\J2E\SYS\exe\run

-> exe path = PATH=C:\j2sdk1.4.2_08\bin;C:\usr\sap\J2E\JC00\j2ee\os_libs;C:\oracle\WAS\92\bin;C:\oracle\WAS\92\jre\1.4.2\bin\client;C:\oracle\WAS\92\jre\1.4.2\bin;C:\Program Files\Oracle\jre\1.3.1\bin;C:\Program Files\Oracle\jre\1.1.8\bin;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\j2sdk1.4.2_08\bin;C:\oracle\WAS\92\Appache\perl\5.00503\bin\MSWin32-x86;C:\usr\sap\J2E\SCS01\exe;C:\usr\sap\J2E\JC00\exe;C:\usr\sap\J2E\SYS\exe\run

**********************************************************************

[Thr 2968] Tue Aug 09 13:59:51 2005

[Thr 2968] JControlICheckProcessList: process SDM started (PID:1556)

[Thr 1188] Tue Aug 09 14:01:01 2005

[Thr 1188] JControlMSMessageFunc: receive command:6, argument:1213679940 from Message Server

[Thr 1188] JControlMSMessageFunc: receive command:6, argument:1213679940 from Message Server

[Thr 1188] JControlMSMessageFunc: receive command:6, argument:1213679940 from Message Server

[Thr 1188] JControlMSMessageFunc: receive command:6, argument:1213679940 from Message Server

[Thr 1188] JControlMSMessageFunc: receive command:6, argument:1213679940 from Message Server

[Thr 1188] JControlMSMessageFunc: receive command:6, argument:1213679940 from Message Server

[Thr 1188] JControlMSMessageFunc: receive command:6, argument:1213679940 from Message Server

[Thr 1188] JControlMSMessageFunc: receive command:6, argument:1213679940 from Message Server

[Thr 1188] Tue Aug 09 14:01:58 2005

[Thr 1188] JControlMSMessageFunc: receive command:6, argument:1213679940 from Message Server

[Thr 1188] JControlMSMessageFunc: receive command:6, argument:1213679940 from Message Server

[Thr 1188] JControlMSMessageFunc: receive command:6, argument:1213679940 from Message Server

[Thr 1188] JControlMSMessageFunc: receive command:6, argument:1213679940 from Message Server

[Thr 1188] JControlMSMessageFunc: receive command:6, argument:1213679940 from Message Server

[Thr 1188] JControlMSMessageFunc: receive command:6, argument:1213679940 from Message Server

[Thr 1188] JControlMSMessageFunc: receive command:6, argument:1213679940 from Message Server

[Thr 1188] JControlMSMessageFunc: receive command:6, argument:1213679940 from Message Server

[Thr 1188] Tue Aug 09 14:10:25 2005

[Thr 1188] JControlMSReadMessage: NiPeek() returns -5 NIETIMEOUT

[Thr 1188] Tue Aug 09 14:15:45 2005

[Thr 1188] JControlMSReadMessage: NiPeek() returns -5 NIETIMEOUT

[Thr 1188] Tue Aug 09 14:20:46 2005

[Thr 1188] JControlMSReadMessage: NiPeek() returns -5 NIETIMEOUT

[Thr 1188] Tue Aug 09 14:26:06 2005

[Thr 1188] JControlMSReadMessage: NiPeek() returns -5 NIETIMEOUT

[Thr 1188] Tue Aug 09 14:31:07 2005

[Thr 1188] JControlMSReadMessage: NiPeek() returns -5 NIETIMEOUT

[Thr 1188] Tue Aug 09 14:36:27 2005

[Thr 1188] JControlMSReadMessage: NiPeek() returns -5 NIETIMEOUT

[Thr 1188] Tue Aug 09 14:41:28 2005

[Thr 1188] JControlMSReadMessage: NiPeek() returns -5 NIETIMEOUT

Then i try to login the visual admin gives me a windows error and the msg_server process shuts down alone. Then i restart that node and agregate the following lines to the trace:

Thr 1188] Tue Aug 09 14:42:25 2005

[Thr 1188] *** ERROR => MsINiRead: NiBufReceive failed (NIECONN_BROKEN) [msxxi.c 2488]

[Thr 1188] *** ERROR => MsIReadFromHdl: NiRead (rc=NIECONN_BROKEN) [msxxi.c 1652]

[Thr 1188] Tue Aug 09 14:42:27 2005

[Thr 1188] ***LOG Q0I=> NiPConnect2: SiPeekPendConn (10061: WSAECONNREFUSED: Connection refused) [nixxi_r.cpp 8588]

[Thr 1188] *** ERROR => MsIAttachEx: NiBufConnect to toshiba-user/3601 failed (rc=NIECONN_REFUSED) [msxxi.c 633]

[Thr 1188] *** WARNING => Can't reconnect to message server (toshiba-user/3601) [rc = -100]-> reconnect [jcntrms.c 295]

[Thr 1188] Tue Aug 09 14:42:32 2005

[Thr 1188] *** ERROR => MsIAttachEx: NiBufConnect to toshiba-user/3601 failed (rc=NIECONN_REFUSED) [msxxi.c 633]

[Thr 1188] *** WARNING => Can't reconnect to message server (toshiba-user/3601) [rc = -100]-> reconnect [jcntrms.c 295]

[Thr 1188] Tue Aug 09 14:42:38 2005

[Thr 1188] *** ERROR => MsIAttachEx: NiBufConnect to toshiba-user/3601 failed (rc=NIECONN_REFUSED) [msxxi.c 633]

[Thr 1188] *** WARNING => Can't reconnect to message server (toshiba-user/3601) [rc = -100]-> reconnect [jcntrms.c 295]

[Thr 1188] Tue Aug 09 14:42:44 2005

[Thr 1188] *** ERROR => MsIAttachEx: NiBufConnect to toshiba-user/3601 failed (rc=NIECONN_REFUSED) [msxxi.c 633]

[Thr 1188] *** WARNING => Can't reconnect to message server (toshiba-user/3601) [rc = -100]-> reconnect [jcntrms.c 295]

[Thr 1188] Tue Aug 09 14:42:49 2005

[Thr 1188] JControlMSConnect: reconnected to message server (toshiba-user/3601)

[Thr 1188] Tue Aug 09 14:48:11 2005

[Thr 1188] JControlMSReadMessage: NiPeek() returns -5 NIETIMEOUT

[Thr 1188] Tue Aug 09 14:53:12 2005

[Thr 1188] JControlMSReadMessage: NiPeek() returns -5 NIETIMEOUT

[Thr 1188] Tue Aug 09 14:58:32 2005

[Thr 1188] JControlMSReadMessage: NiPeek() returns -5 NIETIMEOUT

I try to login the visual admin again and gives me the following error: "Cannot open connection on host: 191.9.6.22 and port: 50004"

Looking the log and trace files i see the following errors:

- SAPEngine_System_Thread[impl:5]_5##0#0#Error#1#/System/Server#Plain###Encomi: failed to connect to toshiba-user/3201(Connection refused: connect)#

- java.net.SocketException: socket closed

at java.net.PlainSocketImpl.socketAccept(Native Method)

at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:353)

at java.net.ServerSocket.implAccept(ServerSocket.java:448)

at java.net.ServerSocket.accept(ServerSocket.java:419)

at com.sap.engine.core.port.impl0.ServerSocketListener.run(ServerSocketListener.java:87)

- erver socket listener opened by service on socket encountered error. The listener will be stopped.#2#p4#ServerSocket[addr=/0.0.0.0,port=0,localport=50004]

I dont know whats happening, if somebody knows i hope that helps me. Please is urgent.

Thx and Rgds.

Gregory

[Former Member]

Check the file

\usr\sap\<SID>\JC00\work\std_server0.out and post the contents.

It could be that this will show(but I don't think is likely as the server is partially up):

"Error occurred during initialization of VM

Could not reserve enough space for object heap"

in which you need to

1) Increase size of page file (for a laptop with 1gb you need a 3gb page file to run sap ep on it with a database server)

or

2) Decrease the memory settings in the configtool (check that the Xmx,Xms and memory.manager settings are not too high)

or

3) Buy more memory

Dagfinn

[gregorw]

Hello Everybody,

this is an old Topic but I've just got the same problem. I've found this OSS Note:

940893 - Analysis of errors within the startup of J2EE Engine 6.40

Regards

Gregor

[Former Member]

Did it just die out or is this a new install?

[gregorw]

Hello David,

in my case the problem occured after installing M$ Support Packages. It seems that the memory allocation of some DLL's has changed. After I've reduced the Heap Size of the JVM from 1024 KByte to 512 it started again. Luckily it's only a Development System.

Regards

Gregor

[Former Member]

Gotta love the support packages for M$.

The other thing may be that the Support Packs are now taking up too much memory. Take it up to 756 and see if it starts, then inch it up or down.

Have you ever rebased your dll's yet?

[gregorw]

Hello David,

my first try was with 756. The serve failed to start. I did not try a rebase. I will give this to our Basis Team to take care of :-).

Regards

Gregor

[Former Member]

Hi Gregory,

the latter messages are related to the message server, which shut down as you said. Without the message server, the cluster communication is not possible.

Restart your whole instance and watch the dev_server0 log file, which can be found under \usr\sap\<sid>\JC00\work

There should be a hint why the server can't be accessed.

If there's no significant message, see what log file is the newest in the work directory.

Regards, Karsten

[Former Member]

Hi, thx a lot both.

Respect the link

http://<hostname>:50<instanceno>00/sap/monitoring/SystemInfo , i cant access it. I cant access by telnet, by visual admin.

In the work folder under \usr\sap\<sid>\JC00 i found that the last updated files are:

- available.txt that contains the following data:

Unavailable 08.08.2005 10:46:53 - 08.08.2005 10:58:54

Available 08.08.2005 10:59:54 - 08.08.2005 13:52:54

Unavailable 08.08.2005 13:53:54 - 08.08.2005 13:53:54

Available 08.08.2005 13:54:54 - 08.08.2005 14:03:54

Unavailable 08.08.2005 14:04:54 - 08.08.2005 14:04:54

Available 08.08.2005 14:05:54 - 08.08.2005 14:34:54

Unavailable 08.08.2005 14:35:54 - 08.08.2005 14:39:44

Unavailable 08.08.2005 14:56:17 - 08.08.2005 16:24:13

Unavailable 08.08.2005 16:28:07 - 08.08.2005 16:29:07

Unavailable 08.08.2005 16:34:36 - 08.08.2005 17:17:58

Unavailable 09.08.2005 08:13:36 - 09.08.2005 08:54:33

Unavailable 09.08.2005 08:57:04 - 09.08.2005 12:46:25

Available 09.08.2005 12:47:25 - 09.08.2005 13:26:25

Available 09.08.2005 13:43:56 - 09.08.2005 13:55:56

Unavailable 09.08.2005 13:56:40 - 09.08.2005 14:04:57

Available 09.08.2005 14:05:57 - 09.08.2005 16:16:57

Unavailable 09.08.2005 16:17:57 - 09.08.2005 17:27:12

Unavailable 10.08.2005 08:10:30 - 10.08.2005 08:35:39

Available 10.08.2005 08:36:39 - 10.08.2005 09:16:39

Available 10.08.2005 12:33:51 - 10.08.2005 14:01:51

- dev_jcontrol that contains the information displayed in the developer trace of jcontrol process(and y mentioned above)

- dev_dispatcher that contains the following info:

[Thr 2664] Wed Aug 10 08:33:04 2005

[Thr 2664] JHVM_RegisterNatives: registering methods in com.sap.bc.proj.jstartup.JStartupFramework

[Thr 2664] JLaunchISetClusterId: set cluster id 5761000

[Thr 2664] JLaunchISetState: change state from [Initial (0)] to [Waiting for start (1)]

[Thr 2664] JLaunchISetState: change state from [Waiting for start (1)] to [Starting (2)]

[Thr 3320] Wed Aug 10 08:33:21 2005

[Thr 3320] JLaunchISetP4Port: set p4 port 50004

[Thr 3528] Wed Aug 10 08:33:26 2005

[Thr 3528] JLaunchISetTelnetPort: set telnet port 50008

[Thr 3528] JLaunchISetTelnetPort: set telnet port 50008

[Thr 3584] Wed Aug 10 08:33:55 2005

[Thr 3584] JLaunchISetHttpPort: set http port 50000

[Thr 2664] Wed Aug 10 08:34:02 2005

[Thr 2664] JLaunchISetState: change state from [Starting (2)] to [Running (3)]

[Thr 2568] Wed Aug 10 08:34:08 2005

[Thr 2568] JHVM_RegisterNatives: registering methods in com.sap.mw.rfc.driver.CpicDriver

[Thr 3660] Wed Aug 10 08:35:07 2005

[Thr 3660] JLaunchISetP4Port: set p4 port 50004

[Thr 3600] Wed Aug 10 08:36:34 2005

[Thr 3600] JLaunchISetHttpPort: set http port 50000

[Thr 3612] Wed Aug 10 12:43:40 2005

[Thr 3612] JLaunchISetHttpPort: set http port 50000

[Thr 3612] JLaunchISetP4Port: set p4 port 50004

[Thr 3612] JLaunchISetTelnetPort: set telnet port 50008

- dev_server0 that contains:

[Thr 2676] Wed Aug 10 08:33:06 2005

[Thr 2676] JHVM_RegisterNatives: registering methods in com.sap.bc.proj.jstartup.JStartupFramework

[Thr 2676] JLaunchISetClusterId: set cluster id 5761050

[Thr 2676] JLaunchISetState: change state from [Initial (0)] to [Waiting for start (1)]

[Thr 2676] JLaunchISetState: change state from [Waiting for start (1)] to [Starting (2)]

[Thr 4296] Wed Aug 10 08:34:58 2005

[Thr 4296] JHVM_RegisterNatives: registering methods in com.sap.mw.rfc.driver.CpicDriver

[Thr 4296] Wed Aug 10 08:35:00 2005

[Thr 4296] JHVM_RegisterNatives: registering methods in com.sap.mw.jco.util.SAPConverters

[Thr 4296] JHVM_RegisterNatives: registering methods in com.sap.mw.jco.util.SAPCharToNUCByteConverter

[Thr 4296] Wed Aug 10 08:35:01 2005

[Thr 4296] JHVM_RegisterNatives: registering methods in com.sap.mw.jco.util.SAPNUCByteToCharConverter

[Thr 2676] Wed Aug 10 08:35:07 2005

[Thr 2676] JLaunchISetState: change state from [Starting (2)] to [Starting applications (10)]

[Thr 208] Wed Aug 10 08:36:34 2005

[Thr 208] JLaunchISetState: change state from [Starting applications (10)] to [Running (3)]

I still dont know whats happening. And i need to solve the problem urgent. I hope u can help me.

Thx and Rgds.

Gregory.

[Former Member]

Hi Gregory,

Check if ports 3201, 3601 are opened in %windows%\system32\etc\drivers\services (\etc\services for Unix) on you PC with a hostname "toshiba-user"

Regards,

Mike

[Former Member]

Hi Mike, thx

I check the services file and i have the lines:

- sapdp01 3201/tcp

- sapmsJ2E 3601/tcp

And executing the comand 'netstat -n' i have that:

TCP 191.9.6.22:50000 191.9.6.22:4055 CLOSE_WAIT

TCP 191.9.6.22:50004 191.9.6.22:3957 CLOSE_WAIT

TCP 191.9.6.22:50008 191.9.6.22:4021 CLOSE_WAIT

TCP 191.9.6.22:3601 191.9.6.22:3936 ESTABLISHED

TCP 191.9.6.22:3601 191.9.6.22:3939 ESTABLISHED

TCP 191.9.6.22:3601 191.9.6.22:3940 ESTABLISHED

TCP 191.9.6.22:3601 191.9.6.22:3941 ESTABLISHED

TCP 191.9.6.22:3201 191.9.6.22:3942 ESTABLISHED

TCP 191.9.6.22:3201 191.9.6.22:3943 ESTABLISHED

Rgds.

Gregory.

[Former Member]

Hi all.

I need that somebody helps me solve this problem urgent.

Thx a lot

Best Regards

Gregory.

[adam_recktenwald]

You might try doing an NSLookup on 'toshiba-user' to see if it resolves your machine's IP.

Also, you could drop the name in the hosts file to guarentee it resolves to the local IP.

C:\WINDOWS\system32\drivers\etc\hosts

You can try both the localhost IP (i.e. 127.0.0.1) or the actual IP of the host.

Hope this help.

-Adam

[Former Member]

Hi Adam, thx.

But i already try that and dont work.

Best rgds.

Gregory.

[Former Member]

Did you try accessing the admin page thru a web browser? You can access it by http://<hostname>:50<instance no.>00/sap/monitoring/SystemInfo