This discussion is archived
2 Replies Latest reply: Dec 6, 2012 12:08 AM by 955331 RSS

Weblogic Start up very slow

955331 Newbie
Currently Being Moderated
Hi all,

The following server log is the task taking the maximum time (when we consider the overall slowness) during the weblogic server start-up. I took some thread dumps in 10 mins interval while the weblogic hang between 7:37:43 and 8:06:32, and i observed that this thread was trying to deploy the application (dms.war), which in-turn was making a call to the DB to get the security policies via the JPS/OPSS call made by "GenericPolicyDistributionService.java". The server was working fine before, used to take max 5 mins to start.
Please advise how to resolve this issue

--
<Dec 3, 2012 7:37:43 PM CST> <Info> <Deployer> <BEA-149060> <Module dms.war of application DMS Application [Version=11.1.1.1.0] successfully transitioned from STATE_PREPARED to STATE_ADMIN on server AdminServer.>
<Dec 3, 2012 8:06:32 PM CST> <Info> <Deployer> <BEA-149059> <Module / of application FMW Welcome Page Application [Version=11.1.0.0.0] is transitioning from STATE_PREPARED to STATE_ADMIN on server AdminServer.>

--


Threaddump
==============

"[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'" id=16 idx=0x40 tid=6476 prio=5 alive, in native, daemon
at jrockit/net/SocketNativeIO.readBytesPinned(Ljava/io/FileDescriptor;[BIII)I(Native Method)
    at jrockit/net/SocketNativeIO.socketRead(SocketNativeIO.java:32)
    at java/net/SocketInputStream.socketRead0(Ljava/io/FileDescriptor;[BIII)I(SocketInputStream.java)
    at java/net/SocketInputStream.read(SocketInputStream.java:129)
    at oracle/net/nt/MetricsEnabledInputStream.read(TcpNTAdapter.java:718)
    at oracle/net/ns/Packet.receive(Packet.java:295)
    at oracle/net/ns/DataPacket.receive(DataPacket.java:106)
    at oracle/net/ns/NetInputStream.getNextPacket(NetInputStream.java:317)
    at oracle/net/ns/NetInputStream.read(NetInputStream.java:262)
    at oracle/net/ns/NetInputStream.read(NetInputStream.java:187)
    at oracle/net/ns/NetInputStream.read(NetInputStream.java:104)
    at oracle/jdbc/driver/T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:126)
    at oracle/jdbc/driver/T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:82)
    at oracle/jdbc/driver/T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1177)
    at oracle/jdbc/driver/T4CMAREngine.unmarshalSB1(T4CMAREngine.java:1153)
    at oracle/jdbc/driver/T4CTTIfun.receive(T4CTTIfun.java:312)
    at oracle/jdbc/driver/T4CTTIfun.doRPC(T4CTTIfun.java:204)
    at oracle/jdbc/driver/T4C8Oall.doOALL(T4C8Oall.java:540)
    at oracle/jdbc/driver/T4CPreparedStatement.doOall8(T4CPreparedStatement.java:217)
    at oracle/jdbc/driver/T4CPreparedStatement.fetch(T4CPreparedStatement.java:1168)
    at oracle/jdbc/driver/OracleResultSetImpl.close_or_fetch_from_next(OracleResultSetImpl.java:628)
    ^-- Holding lock: oracle/jdbc/driver/T4CConnection@0x00000000FF7B90D8[recursive]
at oracle/jdbc/driver/OracleResultSetImpl.next(OracleResultSetImpl.java:490)
^-- Holding lock: oracle/jdbc/driver/T4CConnection@0x00000000FF7B90D8[biased lock]
at weblogic/jdbc/wrapper/ResultSet_oracle_jdbc_driver_OracleResultSetImpl.next()Z(Unknown Source)
at org/eclipse/persistence/internal/databaseaccess/DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:650)
at org/eclipse/persistence/internal/databaseaccess/DatabaseAccessor.executeCall(DatabaseAccessor.java:526)
at org/eclipse/persistence/sessions/server/ServerSession.executeCall(ServerSession.java:529)
at org/eclipse/persistence/internal/queries/DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:206)
at org/eclipse/persistence/internal/queries/DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:192)
at org/eclipse/persistence/internal/queries/DatasourceCallQueryMechanism.executeSelectCall(DatasourceCallQueryMechanism.java:263)
at org/eclipse/persistence/internal/queries/DatasourceCallQueryMechanism.selectAllRows(DatasourceCallQueryMechanism.java:644)
at org/eclipse/persistence/internal/queries/ExpressionQueryMechanism.selectAllRowsFromTable(ExpressionQueryMechanism.java:2537)
at org/eclipse/persistence/internal/queries/ExpressionQueryMechanism.selectAllRows(ExpressionQueryMechanism.java:2496)
at org/eclipse/persistence/queries/ReadAllQuery.executeObjectLevelReadQuery(ReadAllQuery.java:407)
at org/eclipse/persistence/queries/ObjectLevelReadQuery.executeDatabaseQuery(ObjectLevelReadQuery.java:1076)
at org/eclipse/persistence/queries/DatabaseQuery.execute(DatabaseQuery.java:740)
at org/eclipse/persistence/queries/ObjectLevelReadQuery.execute(ObjectLevelReadQuery.java:1036)
at org/eclipse/persistence/queries/ReadAllQuery.execute(ReadAllQuery.java:380)
at org/eclipse/persistence/queries/ObjectLevelReadQuery.executeInUnitOfWork(ObjectLevelReadQuery.java:1122)
at org/eclipse/persistence/internal/sessions/UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:2910)
at org/eclipse/persistence/internal/sessions/AbstractSession.executeQuery(AbstractSession.java:1291)
at org/eclipse/persistence/internal/sessions/AbstractSession.executeQuery(AbstractSession.java:1273)
at org/eclipse/persistence/internal/sessions/AbstractSession.executeQuery(AbstractSession.java:1247)
at org/eclipse/persistence/internal/jpa/EJBQueryImpl.executeReadQuery(EJBQueryImpl.java:479)
at org/eclipse/persistence/internal/jpa/EJBQueryImpl.getResultList(EJBQueryImpl.java:714)
at oracle/security/jps/internal/policystore/rdbms/JpsDBDataManager.getChangedTimestampInDoAs(JpsDBDataManager.java:3523)
at oracle/security/jps/internal/policystore/rdbms/JpsDBDataManager.getChangedTimestamp(JpsDBDataManager.java:3472)
at oracle/security/jps/internal/policystore/entitymanager/impl/InternalQueryManagerImpl.getChangedTimestamp(InternalQueryManagerImpl.java:1137)
at oracle/security/jps/az/internal/management/pd/service/GenericPolicyDistributionService.internalGetObjectModifiedTime(GenericPolicyDistributionService.jav
a:1424)
at oracle/security/jps/az/internal/management/pd/service/GenericPolicyDistributionService.getObjectModifiedTime(GenericPolicyDistributionService.java:1386)
at oracle/security/jps/az/internal/management/pd/service/PolicyDistributionServiceImpl.getObjectModifiedTime(PolicyDistributionServiceImpl.java:226)
at oracle/security/jps/az/internal/runtime/service/PDPServiceImpl.initAppDomain(PDPServiceImpl.java:524)
at oracle/security/jps/az/internal/runtime/service/PDPServiceImpl.initial(PDPServiceImpl.java:231)
at oracle/security/jps/az/internal/runtime/service/PDPServiceImpl.getApplicationPolicyMap(PDPServiceImpl.java:302)
at oracle/security/jps/az/internal/runtime/service/PDPServiceImpl.getApplicationPolicy(PDPServiceImpl.java:331)
at oracle/security/jps/az/internal/runtime/service/PDPServiceImpl.getApplicationPolicy(PDPServiceImpl.java:320)
at oracle/security/jps/internal/policystore/PolicyUtil.getGrantedAppRoles(PolicyUtil.java:2719)
at oracle/security/jps/internal/jaas/JpsAbsSubjectResolver$4.run(JpsAbsSubjectResolver.java:526)
at oracle/security/jps/internal/jaas/JpsAbsSubjectResolver$4.run(JpsAbsSubjectResolver.java:516)
at jrockit/vm/AccessController.doPrivileged(AccessController.java:254)
at jrockit/vm/AccessController.doPrivileged(AccessController.java:268)
at oracle/security/jps/internal/jaas/JpsAbsSubjectResolver.getApplicationRoles(JpsAbsSubjectResolver.java:516)
at oracle/security/jps/internal/jaas/JpsAbsSubjectResolver.createJpsSubject(JpsAbsSubjectResolver.java:363)
at oracle/security/jps/internal/jaas/JpsAbsSubjectResolver.getAuthenticatedSubject(JpsAbsSubjectResolver.java:356)
at oracle/security/jps/internal/jaas/JpsAbsSubjectResolver.resolveJpsSubject(JpsAbsSubjectResolver.java:269)
at oracle/security/jps/internal/jaas/JpsAbsSubjectResolver.resolveSubject(JpsAbsSubjectResolver.java:212)
at oracle/security/jps/ee/jmx/JpsJmxInterceptor.internalPreRegister(JpsJmxInterceptor.java:447)
at oracle/as/jmx/framework/generic/spi/interceptors/AbstractMBeanInterceptor.doPreRegister(AbstractMBeanInterceptor.java:180)
at oracle/as/jmx/framework/generic/spi/interceptors/DefaultMBeanInterceptor.internalPreRegister(DefaultMBeanInterceptor.java:81)
at oracle/as/jmx/framework/generic/spi/interceptors/ContextClassLoaderMBeanInterceptor.internalPreRegister(ContextClassLoaderMBeanInterceptor.java:150)
at oracle/as/jmx/framework/generic/spi/interceptors/AbstractMBeanInterceptor.doPreRegister(AbstractMBeanInterceptor.java:180)
at oracle/as/jmx/framework/generic/spi/interceptors/DefaultMBeanInterceptor.internalPreRegister(DefaultMBeanInterceptor.java:81)
at oracle/as/jmx/framework/generic/spi/interceptors/AbstractMBeanInterceptor.doPreRegister(AbstractMBeanInterceptor.java:180)
at oracle/as/jmx/framework/generic/spi/interceptors/BasePublicMBeanInterceptor.internalPreRegister(BasePublicMBeanInterceptor.java:110)
at oracle/as/jmx/framework/generic/spi/interceptors/LoggingMBeanInterceptor.internalPreRegister(LoggingMBeanInterceptor.java:633)
at oracle/as/jmx/framework/generic/spi/interceptors/AbstractMBeanInterceptor.doPreRegister(AbstractMBeanInterceptor.java:180)
at oracle/as/jmx/framework/standardmbeans/spi/OracleStandardEmitterMBean.preRegister(OracleStandardEmitterMBean.java:611)
at com/sun/jmx/interceptor/DefaultMBeanServerInterceptor.preRegisterInvoke(DefaultMBeanServerInterceptor.java:1010)
at com/sun/jmx/interceptor/DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:938)
at com/sun/jmx/interceptor/DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:917)
at com/sun/jmx/interceptor/DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:312)
at com/sun/jmx/mbeanserver/JmxMBeanServer.registerMBean(JmxMBeanServer.java:482)
at weblogic/management/jmx/mbeanserver/WLSMBeanServerInterceptorBase$27.run(WLSMBeanServerInterceptorBase.java:714)
at jrockit/vm/AccessController.doPrivileged(AccessController.java:254)
at jrockit/vm/AccessController.doPrivileged(AccessController.java:268)
at weblogic/management/jmx/mbeanserver/WLSMBeanServerInterceptorBase.registerMBean(WLSMBeanServerInterceptorBase.java:709)
at weblogic/management/mbeanservers/internal/JMXContextInterceptor.registerMBean(JMXContextInterceptor.java:445)
at weblogic/management/jmx/mbeanserver/WLSMBeanServerInterceptorBase$27.run(WLSMBeanServerInterceptorBase.java:712)
at jrockit/vm/AccessController.doPrivileged(AccessController.java:254)
at jrockit/vm/AccessController.doPrivileged(AccessController.java:268)
at weblogic/management/jmx/mbeanserver/WLSMBeanServerInterceptorBase.registerMBean(WLSMBeanServerInterceptorBase.java:709)
at weblogic/management/jmx/mbeanserver/WLSMBeanServer.registerMBean(WLSMBeanServer.java:462)
at oracle/as/jmx/framework/wls/spi/security/PrivilegedMBeanServerInterceptor$1.run(PrivilegedMBeanServerInterceptor.java:55)
at weblogic/security/acl/internal/AuthenticatedSubject.doAs(AuthenticatedSubject.java:363)
at oracle/as/jmx/framework/wls/spi/security/PrivilegedMBeanServerInterceptor.registerMBean(PrivilegedMBeanServerInterceptor.java:60)
at oracle/as/jmx/framework/wls/spi/security/PrivilegedMBeanServerInterceptor$1.run(PrivilegedMBeanServerInterceptor.java:55)
at weblogic/security/acl/internal/AuthenticatedSubject.doAs(AuthenticatedSubject.java:363)
at oracle/as/jmx/framework/wls/spi/security/PrivilegedMBeanServerInterceptor.registerMBean(PrivilegedMBeanServerInterceptor.java:60)
at oracle/dms/app/BaseInitializer._registerEMIntegrationMBean(BaseInitializer.java:463)
at oracle/dms/app/BaseInitializer.<init>(BaseInitializer.java:139)
at oracle/dms/app/DomainInitializer.<init>(DomainInitializer.java:79)
at oracle/dms/app/BaseInitializer.getInitializer(BaseInitializer.java:228)
^-- Holding lock: java/lang/Class@0x000000009014F7B0[thin lock]
at oracle/dms/app/DmsSpy.init(DmsSpy.java:210)
at weblogic/servlet/internal/StubSecurityHelper$ServletInitAction.run(StubSecurityHelper.java:283)
at weblogic/security/acl/internal/AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
at weblogic/security/service/SecurityManager.runAs(SecurityManager.java:120)
at weblogic/servlet/internal/StubSecurityHelper.createServlet(StubSecurityHelper.java:64)
at weblogic/servlet/internal/StubLifecycleHelper.createOneInstance(StubLifecycleHelper.java:58)
^-- Holding lock: weblogic/servlet/internal/StubLifecycleHelper@0x000000008D8F2FD8[biased lock]
at weblogic/servlet/internal/StubLifecycleHelper.<init>(StubLifecycleHelper.java:48)
at weblogic/servlet/internal/ServletStubImpl.prepareServlet(ServletStubImpl.java:539)
at weblogic/servlet/internal/WebAppServletContext.preloadServlet(WebAppServletContext.java:1985)
at weblogic/servlet/internal/WebAppServletContext.loadServletsOnStartup(WebAppServletContext.java:1959)
at weblogic/servlet/internal/WebAppServletContext.preloadResources(WebAppServletContext.java:1878)
^-- Holding lock: weblogic/servlet/internal/WebAppServletContext@0x0000000090145320[biased lock]
at weblogic/servlet/internal/WebAppServletContext.start(WebAppServletContext.java:3153)
at weblogic/servlet/internal/WebAppModule.startContexts(WebAppModule.java:1508)
at weblogic/servlet/internal/WebAppModule.start(WebAppModule.java:482)
at weblogic/application/internal/flow/ModuleStateDriver$3.next(ModuleStateDriver.java:425)
at weblogic/application/utils/StateMachineDriver.nextState(StateMachineDriver.java:52)
at weblogic/application/internal/flow/ModuleStateDriver.start(ModuleStateDriver.java:119)
at weblogic/application/internal/flow/ScopedModuleDriver.start(ScopedModuleDriver.java:200)
at weblogic/application/internal/flow/ModuleListenerInvoker.start(ModuleListenerInvoker.java:247)
at weblogic/application/internal/flow/ModuleStateDriver$3.next(ModuleStateDriver.java:425)
at weblogic/application/utils/StateMachineDriver.nextState(StateMachineDriver.java:52)
at weblogic/application/internal/flow/ModuleStateDriver.start(ModuleStateDriver.java:119)
at weblogic/application/internal/flow/StartModulesFlow.activate(StartModulesFlow.java:27)
at weblogic/application/internal/BaseDeployment$2.next(BaseDeployment.java:636)
at weblogic/application/utils/StateMachineDriver.nextState(StateMachineDriver.java:52)
at weblogic/application/internal/BaseDeployment.activate(BaseDeployment.java:205)
at weblogic/application/internal/SingleModuleDeployment.activate(SingleModuleDeployment.java:43)
at weblogic/application/internal/DeploymentStateChecker.activate(DeploymentStateChecker.java:161)
at weblogic/deploy/internal/targetserver/AppContainerInvoker.activate(AppContainerInvoker.java:79)
at weblogic/deploy/internal/targetserver/BasicDeployment.activate(BasicDeployment.java:184)
at weblogic/deploy/internal/targetserver/BasicDeployment.activateFromServerLifecycle(BasicDeployment.java:361)
at weblogic/management/deploy/internal/DeploymentAdapter$1.doActivate(DeploymentAdapter.java:51)
at weblogic/management/deploy/internal/DeploymentAdapter.activate(DeploymentAdapter.java:200)
at weblogic/management/deploy/internal/AppTransition$2.transitionApp(AppTransition.java:30)
at weblogic/management/deploy/internal/ConfiguredDeployments.transitionApps(ConfiguredDeployments.java:261)
at weblogic/management/deploy/internal/ConfiguredDeployments.transitionApps(ConfiguredDeployments.java:220)
at weblogic/management/deploy/internal/ConfiguredDeployments.activate(ConfiguredDeployments.java:169)
at weblogic/management/deploy/internal/ConfiguredDeployments.deploy(ConfiguredDeployments.java:123)
at weblogic/management/deploy/internal/DeploymentServerService.resume(DeploymentServerService.java:180)
at weblogic/management/deploy/internal/DeploymentServerService.start(DeploymentServerService.java:96)
at weblogic/t3/srvr/SubsystemRequest.run(SubsystemRequest.java:64)
at weblogic/work/ExecuteThread.execute(ExecuteThread.java:209)
at weblogic/work/ExecuteThread.run(ExecuteThread.java:178)
at jrockit/vm/RNI.c2java(JJJJJ)V(Native Method)
-- end of trace

Legend

  • Correct Answers - 10 points
  • Helpful Answers - 5 points