Hi,
When testing the single-cartridge sample for OpenStack, there were several
occasions of instances not being spawned on the IaaS, without showing any
errors on the logs. The log output contains "Application deployed
successfully", however there are few warning messages related acquiring the
lock on the topology. Other than those entries there are no errors on the
logs, and even after 10-15 minutes, the OpenStack dashboard shows no
spawned instances.
[2015-01-31 17:53:49,922] DEBUG
{org.apache.stratos.autoscaler.applications.parser.DefaultApplicationParser}
- Payload ::
APPLICATION_ID=single-cartridge-app,GROUP_NAME=null,SERVICE_NAME=tomcat,HOST_NAME=
php1.isuruh.lk
,MULTITENANT=false,TENANT_ID=-1234,TENANT_RANGE=*,CARTRIDGE_ALIAS=php1,CLUSTER_ID=php1.tomcat.domain,CARTRIDGE_KEY=oMVzlTBZTAXBaA8m,DEPLOYMENT=default,REPO_URL=
https://github.com/imesh/stratos-tomcat-applications.git,PORTS=22,PROVIDER=apache,PUPPET_IP=192.168.30.96,PUPPET_HOSTNAME=puppet.chamilad.org,PUPPET_DNS_AVAILABLE=null,PUPPET_ENV=null,,,DEPENDENCY_CLUSTER_IDS=,EXPORT_METADATA_KEYS=php1-null,IMPORT_METADATA_KEYS=,TOKEN=eyJhbGciOiJSUzI1NiJ9.eyJleHAiOjEwNzY0NTQ4NDksInN1YiI6ImFkbWluIiwiYXpwIjoiX1dmR2JvZkd3X09DTEZSbEF0QXg2YlE1emFBYSIsImFwcElkIjoic2luZ2xlLWNhcnRyaWRnZS1hcHAiLCJhdWQiOlsiX1dmR2JvZkd3X09DTEZSbEF0QXg2YlE1emFBYSJdLCJpc3MiOiJodHRwczpcL1wvbG9jYWxob3N0Ojk0NDNcL29hdXRoMmVuZHBvaW50c1wvdG9rZW4iLCJpYXQiOjEwNzI4NTQ4NTB9.QSrh9wNeiAxOgDf79h4My-rr4RwwBW29C4aTGmRAP5MvHjZ0SxR8418hLGry9mFqHLXc51WkPiFZSH-1r33sRoAZMVsVheCMy0ZeZoxL5-3-L6cQZ-_m1bp4iZOtblm1bJc105uhBpNeNq7R_GRPVfO08lhDsLn10XkDpirqiC8
[2015-01-31 17:53:49,922] DEBUG
{org.apache.stratos.autoscaler.applications.parser.DefaultApplicationParser}
- Application parsed successfully: [application-id] single-cartridge-app
[2015-01-31 17:53:50,002] DEBUG
{org.apache.stratos.autoscaler.registry.RegistryManager} - Application [
single-cartridge-app ] persisted successfully in the Autoscaler Registry
[2015-01-31 17:53:50,059] DEBUG
{org.apache.stratos.autoscaler.registry.RegistryManager} - Application
context [single-cartridge-app] persisted successfully in the Autoscaler
Registry
[2015-01-31 17:53:50,059] INFO
{org.apache.stratos.autoscaler.services.impl.AutoscalerServiceImpl} -
Application added successfully: [application-id] single-cartridge-app
[2015-01-31 17:53:50,099] DEBUG
{org.apache.stratos.manager.registry.RegistryManager} - Persisting
resource in registry: [resource-path] /stratos.manager/data
[2015-01-31 17:53:50,150] DEBUG
{org.apache.stratos.manager.registry.RegistryManager} - Resource persisted
successfully in registry: [resource-path] /stratos.manager/data
[2015-01-31 17:53:55,211] INFO
{org.apache.stratos.rest.endpoint.api.StratosApiV41Utils} - Starting to
deploy application: [application-id] single-cartridge-app
[2015-01-31 17:53:55,306] DEBUG
{org.apache.stratos.autoscaler.applications.topic.ApplicationBuilder} -
Handling application creation event: [application-id] single-cartridge-app
[2015-01-31 17:53:55,312] INFO
{org.apache.stratos.messaging.domain.application.locking.ApplicationLockHierarchy}
- Added lock for Application single-cartridge-app
[2015-01-31 17:53:55,313] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationHolder} - Trying to
retrieve Applications from registry
[2015-01-31 17:53:55,313] WARN
{org.apache.stratos.autoscaler.applications.topic.ApplicationBuilder} -
Application already exists: [application-id] single-cartridge-app
[2015-01-31 17:53:55,343] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationHolder} - Read lock
acquired
[2015-01-31 17:53:55,343] INFO
{org.apache.stratos.autoscaler.client.CloudControllerClient} - Validating
partitions of policy via cloud controller: [cartridge-type] tomcat
[2015-01-31 17:53:55,352] DEBUG
{org.apache.stratos.cloud.controller.services.impl.CloudControllerServiceImpl}
- Deployment policy validation started for cartridge type: tomcat
[2015-01-31 17:53:55,353] DEBUG
{org.apache.stratos.cloud.controller.concurrent.PartitionValidatorCallable}
- Partition validation started for Partition [id=P1, description=null,
isPublic=false, provider=openstack, partitionMin=0, partitionMax=0,
properties=Properties [properties=[Property [name=region,
value=RegionOne]]]] of Cartridge [type=tomcat, hostName=isuruh.lk,
provider=apache, version=7, multiTenant=false,
defaultAutoscalingPolicy=null, defaultDeploymentPolicy=null,
serviceGroup=null, properties={}, partitionToIaasProvider={}]
[2015-01-31 17:53:55,357] DEBUG
{org.apache.stratos.cloud.controller.iaases.openstack.OpenstackIaas} -
Openstack networking provider is nova. Hence trying to instanstiate
org.apache.stratos.cloud.controller.iaases.openstack.networking.NovaNetworkingApi
[2015-01-31 17:53:57,781] DEBUG
{org.apache.stratos.cloud.controller.iaases.openstack.OpenstackIaas} -
Found a matching region: RegionOne
[2015-01-31 17:53:57,782] DEBUG
{org.apache.stratos.cloud.controller.iaases.openstack.OpenstackIaas} -
Openstack networking provider is nova. Hence trying to instanstiate
org.apache.stratos.cloud.controller.iaases.openstack.networking.NovaNetworkingApi
[2015-01-31 17:54:01,010] DEBUG
{org.apache.stratos.manager.components.ApplicationSignUpHandler} - Reading
application signups
[2015-01-31 17:54:01,011] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationSynchronizeTask} -
Applications Complete Event publisher task has been started...
[2015-01-31 17:54:01,011] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationSynchronizeTask} -
Executing topology synchronization task
[2015-01-31 17:54:01,011] DEBUG
{org.apache.stratos.autoscaler.applications.topic.ApplicationBuilder} -
Handling complete application event
[2015-01-31 17:54:01,012] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationHolder} - Read lock
acquired
[2015-01-31 17:54:01,018] DEBUG
{org.apache.stratos.cloud.controller.messaging.publisher.TopologySynchronizerTask}
- Executing topology synchronization task
[2015-01-31 17:54:01,018] DEBUG
{org.apache.stratos.cloud.controller.messaging.publisher.TopologyEventPublisher}
- Publishing complete topology event
[2015-01-31 17:54:01,020] DEBUG
{org.apache.stratos.manager.messaging.publisher.synchronizer.TenantSynzhronizerTask}
- Publishing complete tenant event
[2015-01-31 17:54:01,045] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationHolder} - Read lock
released
[2015-01-31 17:54:01,086] INFO
{org.apache.stratos.messaging.message.processor.topology.CompleteTopologyMessageProcessor}
- Topology initialized
[2015-01-31 17:54:01,088] INFO
{org.apache.stratos.messaging.message.processor.topology.CompleteTopologyMessageProcessor}
- Topology initialized
[2015-01-31 17:54:01,089] INFO
{org.apache.stratos.autoscaler.event.receiver.topology.AutoscalerTopologyEventReceiver}
- [CompleteTopologyEvent] Received: class
org.apache.stratos.messaging.event.topology.CompleteTopologyEvent
[2015-01-31 17:54:01,089] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationHolder} - Read lock
acquired
[2015-01-31 17:54:01,089] WARN
{org.apache.stratos.messaging.message.receiver.topology.TopologyManager} -
Topology lock not found for Cluster php1.tomcat.domain
[2015-01-31 17:54:01,089] DEBUG
{org.apache.stratos.autoscaler.util.AutoscalerUtil} - [Cluster]
php1.tomcat.domain is not found in the Topology
[2015-01-31 17:54:01,090] WARN
{org.apache.stratos.messaging.message.receiver.topology.TopologyManager} -
Topology lock not found for Cluster php1.tomcat.domain
[2015-01-31 17:54:01,090] ERROR
{org.apache.stratos.autoscaler.event.receiver.topology.AutoscalerTopologyEventReceiver}
- Complete Topology is not consistent with the applications which got
persisted
[2015-01-31 17:54:01,090] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationHolder} - Read lock
released
[2015-01-31 17:54:01,090] INFO
{org.apache.stratos.cep.extension.CEPTopologyEventReceiver} - Complete
topology event received to fault handling window processor.
[2015-01-31 17:54:01,091] INFO
{org.apache.stratos.cep.extension.FaultHandlingWindowProcessor} - Member
timestamps were successfully loaded from the topology
[2015-01-31 17:54:05,109] DEBUG
{org.apache.stratos.cloud.controller.iaases.openstack.OpenstackPartitionValidator}
- Added property region to the IaasProvider.
[2015-01-31 17:54:05,109] DEBUG
{org.apache.stratos.cloud.controller.concurrent.PartitionValidatorCallable}
- Partition Partition [id=P1, description=null, isPublic=false,
provider=openstack, partitionMin=0, partitionMax=0, properties=Properties
[properties=[Property [name=region, value=RegionOne]]]] is validated
successfully against the Cartridge: tomcat
[2015-01-31 17:54:05,110] DEBUG
{org.apache.stratos.cloud.controller.services.impl.CloudControllerServiceImpl}
- Partition P1 added to the cache against cartridge: [cartridge-type]
tomcat
[2015-01-31 17:54:05,111] DEBUG
{org.apache.stratos.cloud.controller.domain.Cartridge} - Partition map
updated for the Cartridge: -868128941. Current Partition List: [P1]
[2015-01-31 17:54:05,111] DEBUG
{org.apache.stratos.cloud.controller.registry.RegistryManager} -
Persisting resource in registry: [resource-path] /cloud.controller/data
[2015-01-31 17:54:05,154] DEBUG
{org.apache.stratos.cloud.controller.registry.RegistryManager} - Resource
persisted successfully in registry: [resource-path] /cloud.controller/data
[2015-01-31 17:54:05,154] INFO
{org.apache.stratos.cloud.controller.services.impl.CloudControllerServiceImpl}
- All partitions [P1] were validated successfully, against the Cartridge:
tomcat
[2015-01-31 17:54:05,163] DEBUG
{org.apache.stratos.autoscaler.client.CloudControllerClient} - Service
call validateDeploymentPolicy() returned in 9820ms
[2015-01-31 17:54:05,163] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationHolder} - Read lock
released
[2015-01-31 17:54:05,163] DEBUG
{org.apache.stratos.autoscaler.pojo.policy.PolicyManager} - Adding
deployment policy: [application-id] single-cartridge-app
[2015-01-31 17:54:05,221] DEBUG
{org.apache.stratos.autoscaler.registry.RegistryManager} - Deployment
policy written to registry: Deployment Policy [applicationId]
single-cartridge-app Description null isPublic false [partitions]
[Partition [id=P1, description=null, isPublic=false, provider=openstack,
properties=Properties [properties=[Property [name=region,
value=RegionOne]]]]]
[2015-01-31 17:54:05,221] INFO
{org.apache.stratos.autoscaler.pojo.policy.PolicyManager} - Deployment
policy is added successfully: [application-id] single-cartridge-app
[2015-01-31 17:54:05,221] INFO
{org.apache.stratos.autoscaler.services.impl.AutoscalerServiceImpl} -
Adding application signup: [application-id] single-cartridge-app
[2015-01-31 17:54:05,230] INFO
{org.apache.stratos.manager.components.ApplicationSignUpHandler} - Adding
application signup: [application-id] single-cartridge-app [tenant-id] -1234
[2015-01-31 17:54:05,234] DEBUG
{org.apache.stratos.manager.registry.RegistryManager} - Persisting
resource in registry: [resource-path]
/stratos.manager/application.signups/single-cartridge-app-tenant--1234
[2015-01-31 17:54:05,446] DEBUG
{org.apache.stratos.manager.registry.RegistryManager} - Resource persisted
successfully in registry: [resource-path]
/stratos.manager/application.signups/single-cartridge-app-tenant--1234
[2015-01-31 17:54:05,461] INFO
{org.apache.stratos.manager.components.ApplicationSignUpHandler} -
Application signup added successfully: [application-id]
single-cartridge-app [tenant-id] -1234
[2015-01-31 17:54:05,462] INFO
{org.apache.stratos.autoscaler.services.impl.AutoscalerServiceImpl} -
Application signup added successfully: [application-id]
single-cartridge-app
[2015-01-31 17:54:05,496] DEBUG
{org.apache.stratos.autoscaler.registry.RegistryManager} - Application
context [single-cartridge-app] persisted successfully in the Autoscaler
Registry
[2015-01-31 17:54:05,496] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationHolder} - Read lock
acquired
[2015-01-31 17:54:05,496] WARN
{org.apache.stratos.messaging.message.receiver.topology.TopologyManager} -
Topology lock not found for Cluster php1.tomcat.domain
[2015-01-31 17:54:05,496] DEBUG
{org.apache.stratos.autoscaler.util.AutoscalerUtil} - [Cluster]
php1.tomcat.domain is not found in the Topology
[2015-01-31 17:54:05,497] WARN
{org.apache.stratos.messaging.message.receiver.topology.TopologyManager} -
Topology lock not found for Cluster php1.tomcat.domain
[2015-01-31 17:54:05,497] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationHolder} - Read lock
released
[2015-01-31 17:54:05,497] INFO
{org.apache.stratos.autoscaler.services.impl.AutoscalerServiceImpl} - The
application clusters are not yet created. Waiting for them to be created
[2015-01-31 17:54:05,499] INFO
{org.apache.stratos.rest.endpoint.api.StratosApiV41Utils} - Application
deployed successfully: [application-id] single-cartridge-app
[2015-01-31 17:55:01,001] DEBUG
{org.apache.stratos.manager.components.ApplicationSignUpHandler} - Reading
application signups
[2015-01-31 17:55:01,003] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationSynchronizeTask} -
Applications Complete Event publisher task has been started...
[2015-01-31 17:55:01,003] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationSynchronizeTask} -
Executing topology synchronization task
[2015-01-31 17:55:01,003] DEBUG
{org.apache.stratos.autoscaler.applications.topic.ApplicationBuilder} -
Handling complete application event
[2015-01-31 17:55:01,003] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationHolder} - Read lock
acquired
[2015-01-31 17:55:01,004] DEBUG
{org.apache.stratos.manager.messaging.publisher.synchronizer.TenantSynzhronizerTask}
- Publishing complete tenant event
[2015-01-31 17:55:01,004] DEBUG
{org.apache.stratos.cloud.controller.messaging.publisher.TopologySynchronizerTask}
- Executing topology synchronization task
[2015-01-31 17:55:01,004] DEBUG
{org.apache.stratos.cloud.controller.messaging.publisher.TopologyEventPublisher}
- Publishing complete topology event
[2015-01-31 17:55:01,030] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationHolder} - Read lock
released
[2015-01-31 17:56:01,001] DEBUG
{org.apache.stratos.manager.components.ApplicationSignUpHandler} - Reading
application signups
[2015-01-31 17:56:01,002] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationSynchronizeTask} -
Applications Complete Event publisher task has been started...
[2015-01-31 17:56:01,003] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationSynchronizeTask} -
Executing topology synchronization task
[2015-01-31 17:56:01,003] DEBUG
{org.apache.stratos.autoscaler.applications.topic.ApplicationBuilder} -
Handling complete application event
[2015-01-31 17:56:01,003] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationHolder} - Read lock
acquired
[2015-01-31 17:56:01,004] DEBUG
{org.apache.stratos.manager.messaging.publisher.synchronizer.TenantSynzhronizerTask}
- Publishing complete tenant event
[2015-01-31 17:56:01,004] DEBUG
{org.apache.stratos.cloud.controller.messaging.publisher.TopologySynchronizerTask}
- Executing topology synchronization task
[2015-01-31 17:56:01,006] DEBUG
{org.apache.stratos.cloud.controller.messaging.publisher.TopologyEventPublisher}
- Publishing complete topology event
[2015-01-31 17:56:01,037] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationHolder} - Read lock
released
[2015-01-31 17:57:01,001] DEBUG
{org.apache.stratos.manager.components.ApplicationSignUpHandler} - Reading
application signups
[2015-01-31 17:57:01,004] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationSynchronizeTask} -
Applications Complete Event publisher task has been started...
[2015-01-31 17:57:01,004] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationSynchronizeTask} -
Executing topology synchronization task
[2015-01-31 17:57:01,005] DEBUG
{org.apache.stratos.autoscaler.applications.topic.ApplicationBuilder} -
Handling complete application event
[2015-01-31 17:57:01,005] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationHolder} - Read lock
acquired
[2015-01-31 17:57:01,005] DEBUG
{org.apache.stratos.manager.messaging.publisher.synchronizer.TenantSynzhronizerTask}
- Publishing complete tenant event
[2015-01-31 17:57:01,006] DEBUG
{org.apache.stratos.cloud.controller.messaging.publisher.TopologySynchronizerTask}
- Executing topology synchronization task
[2015-01-31 17:57:01,006] DEBUG
{org.apache.stratos.cloud.controller.messaging.publisher.TopologyEventPublisher}
- Publishing complete topology event
[2015-01-31 17:57:01,053] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationHolder} - Read lock
released
[2015-01-31 17:58:01,001] DEBUG
{org.apache.stratos.manager.components.ApplicationSignUpHandler} - Reading
application signups
[2015-01-31 17:58:01,003] DEBUG
{org.apache.stratos.manager.messaging.publisher.synchronizer.TenantSynzhronizerTask}
- Publishing complete tenant event
[2015-01-31 17:58:01,003] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationSynchronizeTask} -
Applications Complete Event publisher task has been started...
[2015-01-31 17:58:01,003] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationSynchronizeTask} -
Executing topology synchronization task
[2015-01-31 17:58:01,003] DEBUG
{org.apache.stratos.cloud.controller.messaging.publisher.TopologySynchronizerTask}
- Executing topology synchronization task
[2015-01-31 17:58:01,003] DEBUG
{org.apache.stratos.cloud.controller.messaging.publisher.TopologyEventPublisher}
- Publishing complete topology event
[2015-01-31 17:58:01,003] DEBUG
{org.apache.stratos.autoscaler.applications.topic.ApplicationBuilder} -
Handling complete application event
[2015-01-31 17:58:01,004] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationHolder} - Read lock
acquired
[2015-01-31 17:58:01,054] DEBUG
{org.apache.stratos.autoscaler.applications.ApplicationHolder} - Read lock
released
Regards,
Chamila de Alwis
Software Engineer | WSO2 | +94772207163
Blog: code.chamiladealwis.com
