AS Java server0 Initial status -> hangs if manually started

[Former Member]

Hi Experts,

Would like to seek your help on my issue.

I have a PI 7.10 server running on Windows & MS SQL db (with sapjvm version: 5.1.056, sapjvm build: 51_REL-20100523)

I recently performed a restore (DB & SAP)

Restore was successul, but when trying to start the instance the disp+work hangs at yellow status with "AS Java: Starting the Processes"

I checked the AS Java Process Table and I see that the bootstrap is successful (green) but after that I immediately see the status of components as:

debugproxy --> Status=Disabled

icm --> Status=Initial

server0 --> Status=Initial

I then try to manually start the server0 but it hangs on yellow status with Status=Starting Framework

I checked the std_server0.out and below is the entries:

[Former Member]

Hi,

To start with, shutdown your system completely and start it afresh. ( let it start by itself, wait in case you do not see any errors in the log files)

Did you complete all the post refresh activities.?

Kindly attach the last 200 lines of your dev_server0.log in case your server is not starting.

Regards,

Sonia

[Former Member]

Hi Sonia,

I've tried a full restart even the server itself, but same issue persists.

Here is the last part of the dev_server0.log

J        "Background Jobs Internal Thread" tid=0x0000000021fe2910 parked (1) event=-1 notified=false
J    <0x000000015609c508> (a java.lang.Object) contended monitor=0x0000000023555c58 approx. contending threads=0 wait count=932 recursions=0 
J      owner: NULL (0x0000000000000000)
J      responsible: NULL (0x0000000000000000)
J      successor: NULL (0x0000000000000000)
J      CXQ: Empty
J      EntryList: Empty
J      WaitSet (1 waiter):
J        "Background Jobs Internal Thread" tid=0x00000000239784c0 parked (1) event=-1 notified=false
J    <0x00000001560a0690> (a com.sap.engine.lib.util.WaitQueue) contended monitor=0x0000000023555418 approx. contending threads=0 wait count=163 recursions=0 
J      owner: NULL (0x0000000000000000)
J      responsible: NULL (0x0000000000000000)
J      successor: NULL (0x0000000000000000)
J      CXQ: Empty
J      EntryList: Empty
J      WaitSet (130 waiters):
J        "System [34]" tid=0x00000000004eea90 parked (1) event=-1 notified=false
J        "System [35]" tid=0x00000000004ef5b0 parked (1) event=-1 notified=false
J        "System [36]" tid=0x00000000004f1180 parked (1) event=-1 notified=false
J        "System [37]" tid=0x000000002364ecb0 parked (1) event=-1 notified=false
J        "System [38]" tid=0x000000002364f240 parked (1) event=-1 notified=false
J        "System [39]" tid=0x000000002364f7d0 parked (1) event=-1 notified=false
J        "System [40]" tid=0x000000002364fd60 parked (1) event=-1 notified=false
J        "System [41]" tid=0x00000000236502f0 parked (1) event=-1 notified=false
J        "System [42]" tid=0x0000000023650880 parked (1) event=-1 notified=false
J        "System [43]" tid=0x0000000023650e10 parked (1) event=-1 notified=false
J        "System [44]" tid=0x00000000236513a0 parked (1) event=-1 notified=false
J        "System [45]" tid=0x0000000023651930 parked (1) event=-1 notified=false
J        "System [46]" tid=0x0000000023651ec0 parked (1) event=-1 notified=false
J        "System [47]" tid=0x0000000023652450 parked (1) event=-1 notified=false
J        "System [48]" tid=0x00000000236529e0 parked (1) event=-1 notified=false
J        "System [49]" tid=0x0000000023652f70 parked (1) event=-1 notified=false
J        "System [50]" tid=0x0000000023653500 parked (1) event=-1 notified=false

[Former Member]

Hi ,

I think this is a bug in JDK.

Please import the latest SAP JAM patch and it will solve your issue.

Regards,

VIpin

[Former Member]

node name   : server0
host name   : serverHost
system name : <SID>
system nr.  : <SysNr>
started at  : Wed Feb 29 14:29:01 2012
JVMX version - May 23 2010 07:15:32 - 51_REL - optU - windows amd64 - 6 - bas2:137100 (mixed mode)
(CompilerOracle read from file C:\usr\sap\<SID>\DVEBMGS<SysNr>\exe\sapjvm_5\jre\.hotspot_compiler )
The active factory is : com.sap.engine.boot.loader.StandardClassLoaderFactory
Error! The hash is corrupted C:\usr\sap\<SID>\DVEBMGS<SysNr>\j2ee\cluster\bin\index.list
Reading kernel properties from kernelProperties.bin file...
   Checked the data for 47 ms.
   Read the objects for 437 ms.
   Substituted the values for 47 ms.
Finished reading kernel objects for 484 ms.
StartupFramework returned mode [NORMAL]
StartupFramework returned action [NONE]
SAP J2EE Engine Version 7.10.3710.93810.20100429133313 is starting...
 Loading: LogManager ... 172 ms. 
Loading: PoolManager ... 16 ms. 
Loading: ApplicationThreadManager ... 5.164: [GC 5.165: [ParNew   :    [4352]  14:29:07    ***Warning: Loadavg: Could not collect performance query data.
: 349568K->3872K(524288K), 0.0229366 secs] 349568K->3872K(1922432K), 0.0232033 secs] [Times: user=0.08 sys=0.02, real=0.03 secs] 
531 ms. 
Loading: ThreadManager ... 94 ms. 
Loading: ClassLoaderManager ... 94 ms. 
Loading: ClusterManager ... 328 ms. 
Loading: LockingManager ... 78 ms. 
Loading: ConfigurationManager ... 3359 ms. 
Loading: CacheManager ... 109 ms. 
Loading: DatabaseManager ... 657 ms. 
Loading: SessionManager ... 421 ms. 
Loading: LicensingManager ... 47 ms. 
Loading: ServiceManager ... 
 Initialize components for : 516 ms.
 Resolve components for : 78 ms.
12.317: [GC 12.317: [ParNew: 353440K->28588K(524288K), 0.1028792 secs] 353440K->28588K(1922432K), 0.1033902 secs] [Times: user=0.22 sys=0.16, real=0.11 secs] 
 Load components for 5250 ms.
Loading services.
 Calculate startup service set for 1110 ms.
  Service tcjesecurity~api started. (0 ms / 0 CPU ms)
  Service r3startup started. (0 ms / 0 CPU ms)
  Service engine.lm.log.facade started. (0 ms / 0 CPU ms)
  Service webservices started. (0 ms / 0 CPU ms)
  Service tcjecross~api started. (0 ms / 0 CPU ms)
  Service tcjecontentclassificationhandler started. (0 ms / 0 CPU ms)
  Service cluster started. (31 ms / 15 CPU ms)
  Service runtimeinfo started. (62 ms / 0 CPU ms)
  Service jmx_notification started. (156 ms / 46 CPU ms)
  Service memory started. (281 ms / 203 CPU ms)
  Service timeout started. (312 ms / 78 CPU ms)
  Service userstore started. (188 ms / 62 CPU ms)
  Service cross started. (344 ms / 125 CPU ms)
  Service log_configurator started. (375 ms / 171 CPU ms)
  Service tcsecdestinations~provider started. (406 ms / 265 CPU ms)
  Service locking started. (32 ms / 15 CPU ms)
  Service http started. (547 ms / 515 CPU ms)
  Service schemaprocessor~srv started. (2109 ms / 1906 CPU ms)
Timed out services:
Service tclmctcconfsservice_sda > waits for 2 : [security, security] components to be started.
Service tcesiesp~srv > waits for 3 : [engine.application.facade, engine.service.facade, engine.sld.facade] components to be started.
.....
Timed out services:
2012-02-29 14:59:20
Full thread dump SAP Java Server VM (5.1.056 May 23 2010 07:15:32 - 51_REL - optU - windows amd64 - 6 - bas2:137100 (mixed mode)):
"HTTP Worker [49]" cpu=0.00 [reset 0.00] ms allocated=18352 B (17.92 kB) [reset 18352 B (17.92 kB)]
io= file i/o: 0/0 B, net i/o: 0/0 B, files opened:0, socks opened:0  [reset file i/o: 0/0 B, net i/o: 0/0 B, files opened:0, socks opened:0 ] 
prio=6 tid=0x000000002434d940 nid=0x10ac waiting for monitor entry  [_thread_blocked (_at_safepoint), stack(0x00000000457f0000,0x00000000459f0000)] [0x00000000459ee000..0x00000000459ef750]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at com.sap.bc.proj.jstartup.fca.FCAServer.accept()Lcom/sap/bc/proj/jstartup/fca/FCAConnection;(FCAServer.java:112)
	- waiting to lock <0x0000000148d0f308> (a com.sap.bc.proj.jstartup.fca.FCAServer)
	at com.sap.engine.services.httpserver.server.Processor$FCAProcessorThread.run()V(Processor.java:198)
	at com.sap.engine.core.thread.impl3.ActionObject.run()Ljava/lang/Object;(ActionObject.java:37)
	at java.security.AccessController.doPrivileged(Ljava/security/PrivilegedAction;Ljava/security/AccessControlContext;)Ljava/lang/Object;(Native Method)
	at com.sap.engine.core.thread.impl3.SingleThread.execute(Lcom/sap/engine/core/thread/ThreadContextImpl;)V(SingleThread.java:152)
	at com.sap.engine.core.thread.impl3.SingleThread.run()V(SingleThread.java:181)
   Locked ownable synchronizers:
	- None

[Former Member]

Then I checked the dev_w* and this is what I see:

A Wed Feb 29 16:19:20 2012
A  TH VERBOSE LEVEL FULL
A  ** RABAX: level LEV_RX_PXA_RELEASE_MTX entered.
A  ** RABAX: level LEV_RX_PXA_RELEASE_MTX completed.
A  ** RABAX: level LEV_RX_COVERAGE_ANALYSER entered.
A  ** RABAX: level LEV_RX_COVERAGE_ANALYSER completed.
A  ** RABAX: level LEV_RX_SAVE_SHMLOCKS entered.
A  ** RABAX: level LEV_RX_SAVE_SHMLOCKS completed.
A  ** RABAX: level LEV_RX_RESET_SHMLOCKS entered.
A  ** RABAX: level LEV_RX_RESET_SHMLOCKS completed.
A  ** RABAX: level LEV_RX_ROLLBACK entered.
A  ** RABAX: level LEV_RX_ROLLBACK completed.
A  ** RABAX: level LEV_RX_DB_ALIVE entered.
A  ** RABAX: level LEV_RX_DB_ALIVE completed.
A  ** RABAX: level LEV_RX_HOOKS entered.
A  ** RABAX: level LEV_RX_HOOKS completed.
A  ** RABAX: level LEV_RX_STANDARD entered.
A  ** RABAX: level LEV_RX_STANDARD completed.
A  ** RABAX: level LEV_RX_STOR_VALUES entered.
A  ** RABAX: level LEV_RX_STOR_VALUES completed.
A  ** RABAX: level LEV_RX_C_STACK entered.
A  ** RABAX: level LEV_RX_C_STACK completed.
A  ** RABAX: level LEV_RX_MEMO_CHECK entered.
A  ** RABAX: level LEV_RX_MEMO_CHECK completed.
A  ** RABAX: level LEV_RX_AFTER_MEMO_CHECK entered.
A  ** RABAX: level LEV_RX_AFTER_MEMO_CHECK completed.
A  ** RABAX: level LEV_RX_INTERFACES entered.
A  ** RABAX: level LEV_RX_INTERFACES completed.
A  ** RABAX: level LEV_RX_GET_MESS entered.
A  ** RABAX: level LEV_RX_GET_MESS completed.
A  ** RABAX: level LEV_RX_INIT_SNAP entered.
A  ** RABAX: level LEV_RX_INIT_SNAP completed.
A  ** RABAX: level LEV_RX_WRITE_SYSLOG entered.
A  ** RABAX: level LEV_RX_WRITE_SYSLOG completed.
A  ** RABAX: level LEV_RX_WRITE_SNAP_BEG entered.
A  ** RABAX: level LEV_RX_WRITE_SNAP_BEG completed.
A  ** RABAX: level LEV_RX_WRITE_SNAP entered.
A  ** RABAX: level LEV_SN_END completed.
A  ** RABAX: level LEV_RX_WRITE_SNAP_END entered.
A  ** RABAX: level LEV_RX_WRITE_SNAP_END completed.
A  ** RABAX: level LEV_RX_SET_ALERT entered.
A  ** RABAX: level LEV_RX_SET_ALERT completed.
A  ** RABAX: level LEV_RX_COMMIT entered.
A  ** RABAX: level LEV_RX_COMMIT completed.
A  ** RABAX: level LEV_RX_SNAP_SYSLOG entered.
A  ** RABAX: level LEV_RX_SNAP_SYSLOG completed.
A  ** RABAX: level LEV_RX_RESET_PROGS entered.
A  ** RABAX: level LEV_RX_RESET_PROGS completed.
A  ** RABAX: level LEV_RX_STDERR entered.
A  Wed Feb 29 16:19:20 2012
A  
A  ABAP Program com.sap.vmc.bootstrap.Bootstrap         .
A  Source                                          Line 0.
A  Error Code VM_STACK_TRACE.
A  Module  $Id: //bas/710_REL/src/krn/th/thxxvmc.c#29 $ SAP.
A  Function ThVmcWriteStackTraceShortDump Line 8144.
A  ** RABAX: level LEV_RX_STDERR completed.
A  ** RABAX: level LEV_RX_RFC_ERROR entered.
A  ** RABAX: level LEV_RX_RFC_ERROR completed.
A  ** RABAX: level LEV_RX_RFC_CLOSE entered.
A  ** RABAX: level LEV_RX_RFC_CLOSE completed.
A  ** RABAX: level LEV_RX_IMC_ERROR entered.
A  ** RABAX: level LEV_RX_IMC_ERROR completed.
A  ** RABAX: level LEV_RX_DATASET_CLOSE entered.
A  ** RABAX: level LEV_RX_DATASET_CLOSE completed.
A  ** RABAX: level LEV_RX_ERROR_SAVE entered.
A  ** RABAX: level LEV_RX_ERROR_SAVE completed.
A  ** RABAX: level LEV_RX_ERROR_TPDA entered.
A  ** RABAX: level LEV_RX_ERROR_TPDA completed.
A  ** RABAX: level LEV_RX_PXA_RELEASE_RUDI entered.
A  ** RABAX: level LEV_RX_PXA_RELEASE_RUDI completed.
A  ** RABAX: level LEV_RX_LIVE_CACHE_CLEANUP entered.
A  ** RABAX: level LEV_RX_LIVE_CACHE_CLEANUP completed.
A  ** RABAX: level LEV_RX_END entered.
A  ** RABAX: level LEV_RX_END completed.
A  ** RABAX: end RX_RETURN
A  A Java VM stack trace was created..

above is seen also as Dumps in ST22

Line: -

---

M  ThVmcEndStackTrace: end stack trace of V1
M  *** ERROR => ThJGetVmResp2: received resp VMC_J_VM_ABORT [thxxjava.c   5516]
M  ThVmcCreateStackTrace: create stack trace >Java VM abort<, inProcess=0, fromSched=1
M  *** ERROR => ThJDeleteVm: Tried 5 times to create vms but failed. Deactivate VMC [thxxjava.c   4895]
M  ThVmcDeactivate: deactivate VMC
M  DpVmcSetActive: set vmc state DP_VMC_ENABLED
M  ThPlgSendErrTxt2: invalid tid/mode/plugin_info_hdl (22/0/0)
M  in_ThErrHandle: 1
M  *** ERROR => ThJHandleVmError: java vm returned after error (step 4, th_errno 5, action 1, level 1) [thxxhead.c   11080]
M  DpVmcGetVmByTmAdm: no VM found for T22/M0/I0 (locked VMs ignored)
M  ThResetEmMagic: reset em magic for T22/M0/I0

Line: -

---

Aside from this I checked on DB level and I see from the log:

Error: 18456, Severity:14, state:16

Login failed for user 'NT AUTHORITY\SYSTEM'.[CLIENT:<local machine>]

I hope I've provided enough information above for anyone who can help me resolve this error.

Thanks in advanced