search

wso2 / product-apim

Welcome to the WSO2 API Manager source code! For info on working with the WSO2 API Manager repository and contributing code, click the link below.
http://wso2.github.io/
Apache License 2.0
836 stars 777 forks source link

[APIM 3.1.0] Slow start on Redhat7 #8351

Open Exynos070 opened 4 years ago

Exynos070 commented 4 years ago

I'm trying to run the Api Manager(3.1.0) on redhat 7 . With default setting and start the server use below cmd: sh wso2server.sh -Dhttp.proxyHost=proxyIp -Dhttp.proxyPort=proxyport.

The start is very slow (>3 hours). It shows lot of Waiting for required OSGi services The detail logs:

[2020-06-03 07:44:13,152]  WARN - StartupFinalizerServiceComponent Waiting for required OSGi services: org.wso2.carbon.application.deployer.service.CappDeploymentService,org.wso2.carbon.server.admin.common.IServerAdmin,org.wso2.carbon.throttling.agent.ThrottlingAgent,
[2020-06-03 07:44:22,705]  INFO - EventStreamDeployer Stream definition is deployed successfully  : org.wso2.apimgt.token.revocation.stream:1.0.0
[2020-06-03 07:44:46,758]  INFO - EventStreamDeployer Stream definition is deployed successfully  : org.wso2.blocking.request.stream:1.0.0
[2020-06-03 07:44:49,082]  WARN - AppDeployerServiceComponent Waiting for required OSGi services: org.wso2.carbon.application.deployer.synapse.service.SynapseAppDeployerService,org.wso2.carbon.mediation.initializer.services.SynapseEnvironmentService,
[2020-06-03 07:45:10,812]  INFO - EventStreamDeployer Stream definition is deployed successfully  : org.wso2.botDetectionData.request.stream:1.0.0
[2020-06-03 07:45:13,152]  WARN - StartupFinalizerServiceComponent Waiting for required OSGi services: org.wso2.carbon.application.deployer.service.CappDeploymentService,org.wso2.carbon.server.admin.common.IServerAdmin,org.wso2.carbon.throttling.agent.ThrottlingAgent,
[2020-06-03 07:45:34,868]  INFO - EventStreamDeployer Stream definition is deployed successfully  : org.wso2.keytemplate.request.stream:1.0.0
[2020-06-03 07:45:49,082]  WARN - AppDeployerServiceComponent Waiting for required OSGi services: org.wso2.carbon.application.deployer.synapse.service.SynapseAppDeployerService,org.wso2.carbon.mediation.initializer.services.SynapseEnvironmentService,
[2020-06-03 07:45:58,920]  INFO - EventStreamDeployer Stream definition is deployed successfully  : org.wso2.throttle.globalThrottle.stream:1.0.0
[2020-06-03 07:46:13,152]  WARN - StartupFinalizerServiceComponent Waiting for required OSGi services: org.wso2.carbon.application.deployer.service.CappDeploymentService,org.wso2.carbon.server.admin.common.IServerAdmin,org.wso2.carbon.throttling.agent.ThrottlingAgent,
[2020-06-03 07:46:22,974]  INFO - EventStreamDeployer Stream definition is deployed successfully  : org.wso2.throttle.globalThrottle.stream:1.1.0
[2020-06-03 07:46:47,031]  INFO - EventStreamDeployer Stream definition is deployed successfully  : org.wso2.throttle.processed.request.stream:1.0.0
[2020-06-03 07:46:49,082]  WARN - AppDeployerServiceComponent Waiting for required OSGi services: org.wso2.carbon.application.deployer.synapse.service.SynapseAppDeployerService,org.wso2.carbon.mediation.initializer.services.SynapseEnvironmentService,
[2020-06-03 07:47:11,087]  INFO - EventStreamDeployer Stream definition is deployed successfully  : org.wso2.throttle.request.stream:1.0.0
[2020-06-03 07:47:13,152]  WARN - StartupFinalizerServiceComponent Waiting for required OSGi services: org.wso2.carbon.application.deployer.service.CappDeploymentService,org.wso2.carbon.server.admin.common.IServerAdmin,org.wso2.carbon.throttling.agent.ThrottlingAgent,
[2020-06-03 07:47:35,186]  INFO - EventJunction WSO2EventConsumer added to the junction. Stream:id_gov_notify_stream:1.0.0
[2020-06-03 07:47:49,082]  WARN - AppDeployerServiceComponent Waiting for required OSGi services: org.wso2.carbon.application.deployer.synapse.service.SynapseAppDeployerService,org.wso2.carbon.mediation.initializer.services.SynapseEnvironmentService,
[2020-06-03 07:47:59,243]  INFO - EventPublisherDeployer Event Publisher configuration successfully deployed and in active state : EmailPublisher
[2020-06-03 07:48:13,151]  WARN - StartupFinalizerServiceComponent Waiting for required OSGi services: org.wso2.carbon.application.deployer.service.CappDeploymentService,org.wso2.carbon.server.admin.common.IServerAdmin,org.wso2.carbon.throttling.agent.ThrottlingAgent,
[2020-06-03 07:48:23,298]  INFO - EventJunction WSO2EventConsumer added to the junction. Stream:org.wso2.apimgt.recommendation.event.stream:1.0.0
[2020-06-03 07:48:47,357]  INFO - EventPublisherDeployer Event Publisher configuration successfully deployed and in active state : HTTP-recommendationEventPublisher
[2020-06-03 07:48:49,082]  WARN - AppDeployerServiceComponent Waiting for required OSGi services: org.wso2.carbon.application.deployer.synapse.service.SynapseAppDeployerService,org.wso2.carbon.mediation.initializer.services.SynapseEnvironmentService,
[2020-06-03 07:49:11,413]  INFO - EventJunction WSO2EventConsumer added to the junction. Stream:org.wso2.blocking.request.stream:1.0.0
[2020-06-03 07:49:13,151]  WARN - StartupFinalizerServiceComponent Waiting for required OSGi services: org.wso2.carbon.application.deployer.service.CappDeploymentService,org.wso2.carbon.server.admin.common.IServerAdmin,org.wso2.carbon.throttling.agent.ThrottlingAgent,
[2020-06-03 07:49:35,493]  INFO - EventPublisherDeployer Event Publisher configuration successfully deployed and in active state : blockingEventJMSPublisher
[2020-06-03 07:49:49,083]  WARN - AppDeployerServiceComponent Waiting for required OSGi services: org.wso2.carbon.application.deployer.synapse.service.SynapseAppDeployerService,org.wso2.carbon.mediation.initializer.services.SynapseEnvironmentService,
[2020-06-03 07:49:59,546]  INFO - EventJunction WSO2EventConsumer added to the junction. Stream:org.wso2.apimgt.cache.invalidation.stream:1.0.0

Then i set every log level to debug in log4j2.properties. And i get below errorMessage in wso2-apigw-errors.log:


JAVA_HOME environment variable is set to /usr/local/jdk1.8.0_191
CARBON_HOME environment variable is set to /usr/lib64/wso2/wso2am/3.1.0
Using Java memory options: -Xms256m -Xmx1024m
OSGi console has been enabled with options: -console
andes [org.wso2.andes.wso2.internal.QpidBundleActivator] INFO : Setting BundleContext in PluginManager
callhome [org.wso2.callhome.internal.CallHomeActivator] DEBUG : Activating CallHome agent
osgi> [2020-06-16 04:38:36,938]  INFO - EventAdminConfigurationNotifier Sending Event Admin nofification (configuration successful) to org/ops4j/pax/logging/Configuration
[2020-06-16 04:38:46,872] DEBUG - CacheCleanupTask Cache expiry scheduler running...
[2020-06-16 04:39:07,521]  INFO - JmxReporterBuilder Creating JMX reporter for Metrics with domain 'org.wso2.carbon.metrics'
[2020-06-16 04:39:10,945] DEBUG - CacheCleanupTask Cache expiry completed for the cache: $__local__$.TENANT_CACHE
[2020-06-16 04:39:11,025]  WARN - ds Getting a lock required more than 10000 ms. There might be a synchronization problem in this callstack or just the build/dispose process of some components took too long!
java.lang.Exception: Debug stacktrace
        at org.eclipse.equinox.internal.ds.InstanceProcess.getLock(InstanceProcess.java:120) [org.eclipse.equinox.ds_1.4.400.v20160226-2036.jar:?]
        at org.eclipse.equinox.internal.ds.InstanceProcess.buildComponent(InstanceProcess.java:560) [org.eclipse.equinox.ds_1.4.400.v20160226-2036.jar:?]
        at org.eclipse.equinox.internal.ds.ServiceReg.getService(ServiceReg.java:53) [org.eclipse.equinox.ds_1.4.400.v20160226-2036.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:216) [org.eclipse.osgi_3.14.0.v20190517-1309.jar:?]
        at java.security.AccessController.doPrivileged(Native Method) [?:1.8.0_191]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:213) [org.eclipse.osgi_3.14.0.v20190517-1309.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:114) [org.eclipse.osgi_3.14.0.v20190517-1309.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:48) [org.eclipse.osgi_3.14.0.v20190517-1309.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:530) [org.eclipse.osgi_3.14.0.v20190517-1309.jar:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:464) [org.eclipse.osgi_3.14.0.v20190517-1309.jar:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:685) [org.eclipse.osgi_3.14.0.v20190517-1309.jar:?]
        at org.eclipse.equinox.internal.event.EventHandlerWrapper$1.run(EventHandlerWrapper.java:137) [org.eclipse.equinox.event_1.5.100.v20190528-1257.jar:?]
        at org.eclipse.equinox.internal.event.EventHandlerWrapper$1.run(EventHandlerWrapper.java:1) [org.eclipse.equinox.event_1.5.100.v20190528-1257.jar:?]
        at java.security.AccessController.doPrivileged(Native Method) [?:1.8.0_191]
        at org.eclipse.equinox.internal.event.EventHandlerWrapper.getHandler(EventHandlerWrapper.java:134) [org.eclipse.equinox.event_1.5.100.v20190528-1257.jar:?]
        at org.eclipse.equinox.internal.event.EventHandlerWrapper.handleEvent(EventHandlerWrapper.java:199) [org.eclipse.equinox.event_1.5.100.v20190528-1257.jar:?]
        at org.eclipse.equinox.internal.event.EventHandlerTracker.dispatchEvent(EventHandlerTracker.java:203) [org.eclipse.equinox.event_1.5.100.v20190528-1257.jar:?]
        at org.eclipse.equinox.internal.event.EventHandlerTracker.dispatchEvent(EventHandlerTracker.java:1) [org.eclipse.equinox.event_1.5.100.v20190528-1257.jar:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) [org.eclipse.osgi_3.14.0.v20190517-1309.jar:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:345) [org.eclipse.osgi_3.14.0.v20190517-1309.jar:?]
[2020-06-16 04:39:28,800] DEBUG - ManagerBase Start expire sessions StandardManager at 1592282368800 sessioncount 0

And more info under path repository\components\default\configuration

!ENTRY org.eclipse.equinox.ds 1 0 2020-06-02 08:58:44.568
!MESSAGE Could not bind a reference of component carbon.consent.mgt.component. The reference is: Reference[name = receipt.dao, interface = org.wso2.carbon.consent.mgt.core.dao.ReceiptDAO, policy = dynamic, cardinality = 0..n, target = null, bind = setReceiptDAO, unbind = unsetReceiptDAO]

!ENTRY org.eclipse.equinox.ds 2 0 2020-06-02 08:58:55.040
!MESSAGE Getting a lock required more than 10000 ms. There might be a synchronization problem in this callstack or just the build/dispose process of some components took too long! 
!STACK 0
java.lang.Exception: Debug stacktrace
    at org.eclipse.equinox.internal.ds.InstanceProcess.getLock(InstanceProcess.java:120)
    at org.eclipse.equinox.internal.ds.InstanceProcess.buildComponents(InstanceProcess.java:159)
    at org.eclipse.equinox.internal.ds.Resolver.getEligible(Resolver.java:343)
    at org.eclipse.equinox.internal.ds.SCRManager.serviceChanged(SCRManager.java:222)
    at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:113)
    at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:985)
    at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234)
    at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:151)
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:866)
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:804)
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:130)
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:228)
    at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:525)
    at org.eclipse.equinox.http.servlet.internal.Activator.registerHttpService(Activator.java:81)
    at org.eclipse.equinox.http.servlet.internal.Activator.addProxyServlet(Activator.java:60)
    at org.eclipse.equinox.http.servlet.internal.ProxyServlet.init(ProxyServlet.java:40)
    at org.wso2.carbon.tomcat.ext.servlet.DelegationServlet.init(DelegationServlet.java:38)
    at org.apache.catalina.core.StandardWrapper.initServlet(StandardWrapper.java:1134)
    at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1089)
    at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:983)
    at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:4871)
    at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5180)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1384)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1374)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
    at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:140)
    at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:909)
    at org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:841)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1384)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1374)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
    at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:140)
    at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:909)
    at org.apache.catalina.core.StandardEngine.startInternal(StandardEngine.java:262)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
    at org.wso2.carbon.tomcat.ext.service.ExtendedStandardService.startInternal(ExtendedStandardService.java:52)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
    at org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:930)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
    at org.wso2.carbon.tomcat.internal.CarbonTomcat.start(CarbonTomcat.java:113)
    at org.wso2.carbon.tomcat.internal.ServerManager$1.run(ServerManager.java:167)
    at java.base/java.lang.Thread.run(Thread.java:834)

!ENTRY org.eclipse.equinox.ds 2 0 2020-06-02 08:59:05.042
!MESSAGE Getting a lock required more than 10000 ms. There might be a synchronization problem in this callstack or just the build/dispose process of some components took too long! 
!STACK 0
java.lang.Exception: Debug stacktrace
    at org.eclipse.equinox.internal.ds.InstanceProcess.getLock(InstanceProcess.java:120)
    at org.eclipse.equinox.internal.ds.InstanceProcess.buildComponents(InstanceProcess.java:175)
    at org.eclipse.equinox.internal.ds.Resolver.getEligible(Resolver.java:343)
    at org.eclipse.equinox.internal.ds.SCRManager.serviceChanged(SCRManager.java:222)
    at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:113)
    at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:985)
    at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234)
    at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:151)
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:866)
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:804)
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:130)
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:228)
    at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:525)
    at org.eclipse.equinox.http.servlet.internal.Activator.registerHttpService(Activator.java:81)
    at org.eclipse.equinox.http.servlet.internal.Activator.addProxyServlet(Activator.java:60)
    at org.eclipse.equinox.http.servlet.internal.ProxyServlet.init(ProxyServlet.java:40)
    at org.wso2.carbon.tomcat.ext.servlet.DelegationServlet.init(DelegationServlet.java:38)
    at org.apache.catalina.core.StandardWrapper.initServlet(StandardWrapper.java:1134)
    at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1089)
    at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:983)
    at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:4871)
    at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5180)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1384)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1374)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
    at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:140)
    at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:909)
    at org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:841)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1384)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1374)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
    at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:140)
    at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:909)
    at org.apache.catalina.core.StandardEngine.startInternal(StandardEngine.java:262)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
    at org.wso2.carbon.tomcat.ext.service.ExtendedStandardService.startInternal(ExtendedStandardService.java:52)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
    at org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:930)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
    at org.wso2.carbon.tomcat.internal.CarbonTomcat.start(CarbonTomcat.java:113)
    at org.wso2.carbon.tomcat.internal.ServerManager$1.run(ServerManager.java:167)
    at java.base/java.lang.Thread.run(Thread.java:834)

Can anyone help?

chriswatia commented 2 years ago

@Exynos070 did you find any solution for this issue, experiencing slow start on APIM 3.2.0.