2 Replies Latest reply: Dec 6, 2012 2:08 AM by 955331 RSS

    Weblogic Start up very slow

    955331
      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