Hi Shaheed, Shall we try the following approach to narrow down the problem:
- Try to deploy one application at a time (separately in a fresh Stratos environment) and see whether there are any problems. - Try to use Mock IaaS to speed up the verification and later move to the actual IaaS - If you still see problems, please share the complete set of artifacts so that we could also try the same scenario with Mock IaaS and verify whether there any functional issues. Thanks On Tue, Mar 17, 2015 at 9:36 PM, Shaheedur Haque (shahhaqu) < [email protected]> wrote: > > > What is even more weird is that according to our “topologylistener”, the > Complete Topology Events on the message bus indicate the “broken” > subscription’s VM is Active. So in summary: > > > > · The second subscription is stuck until the third one is attempted > > · When it gets unstuck, the launched VM is never marked as active, > even though the logs and the message bus say it is active > > > > > > *From:* Shaheedur Haque (shahhaqu) > *Sent:* Tuesday, March 17, 2015 3:40 PM > *To:* [email protected] > *Cc:* Ryan Du Plessis (rdupless) > *Subject:* RE: Only one of two single-VM applications coming up in 30 > minutes > > > > OK, so I have proved that while the second subscription is in the “stuck” > state, if I launch a third subscription, the log for the bad one shows all > the “missing” created/activated events as if the third subscription > “unblocks” the second. However, the second never goes active **even > though the third one does go active**: > > > > $ ./bin/orchestration stratos-login --admin describe-application-runtime > third > > Application: third > > {"multiTenant":false,"status":"Active"} > > > > Please advise, > > > > Thanks, Shaheed > > > > *From:* Shaheedur Haque (shahhaqu) > *Sent:* Tuesday, March 17, 2015 12:33 PM > *To:* [email protected] > *Cc:* Ryan Du Plessis (rdupless) > *Subject:* Only one of two single-VM applications coming up in 30 minutes > > > > Hi all, > > > > I’m working with Stratos 4.1, updated very recently and am trying to spin > up two single-VM applications. I can see only one of the two go active: > > > > $ ./bin/orchestration stratos-login --admin describe-application-runtime > cartridge-proxy > > Application: cartridge-proxy > > {"multiTenant":false,"status":"Inactive"} > > $ ./bin/orchestration stratos-login --admin describe-application-runtime > cisco-sample-vm > > Application: cisco-sample-vm > > {"multiTenant":false,"status":"Active"} > > > > When I look at the logs, the broken one reports no errors, but also never > logs messages like the good one about getting allocated IP addresses. The > differences start here (good log): > > > > TID: [0] [STRATOS] [2015-03-17 08:46:38,547] INFO > {org.apache.stratos.autoscaler.util.AutoscalerUtil} - Monitor started > successfully: [application] cisco-sample-vm [dependents] > cisco-sample-vm.cisco-sample-vm.cisco-sample-vm.domain [startup-time] 0 > seconds > > TID: [0] [STRATOS] [2015-03-17 08:46:39,890] INFO > {org.apache.stratos.cloud.controller.services.impl.CloudControllerServiceImpl} > - All partitions [whole-region] were validated successfully, against the > Cartridge: cisco-sample-vm > > TID: [0] [STRATOS] [2015-03-17 08:46:40,358] INFO > {org.apache.stratos.cloud.controller.messaging.publisher.TopologyEventPublisher} > - Publishing cluster instance created event: [service-name] > cisco-sample-vm [cluster-id] > cisco-sample-vm.cisco-sample-vm.cisco-sample-vm.domain in > [network-partition-id] null [instance-id] cisco-sample-vm-1 > > TID: [0] [STRATOS] [2015-03-17 08:46:40,401] INFO > {org.apache.stratos.autoscaler.monitor.MonitorFactory} - ClusterMonitor > created: ClusterMonitor > [clusterId=cisco-sample-vm.cisco-sample-vm.cisco-sample-vm.domain, > hasPrimary=false > > > > And the bad log seemingly ends here: > > > > TID: [0] [STRATOS] [2015-03-17 08:46:38,019] INFO > {org.apache.stratos.autoscaler.util.AutoscalerUtil} - Monitor started > successfully: [application] cartridge-proxy [dependents] > cartridge-proxy.cartridge-proxy.cartridge-proxy.domain [startup-time] 0 > seconds > > TID: [0] [STRATOS] [2015-03-17 08:46:38,986] INFO > {org.apache.stratos.cloud.controller.services.impl.CloudControllerServiceImpl} > - All partitions [whole-region] were validated successfully, against the > Cartridge: cartridge-proxy > > > > At first, I thought that the bad application never gets launched, but it > does in fact, about 30 minutes later: > > > > TID: [0] [STRATOS] [2015-03-17 09:13:00,560] INFO > {org.apache.stratos.cloud.controller.messaging.topology.TopologyBuilder} - > Application Cluster system.cartridge-proxy.cartridge-proxy.domain created > in CC topology > > TID: [0] [STRATOS] [2015-03-17 09:13:00,584] INFO > {org.apache.stratos.messaging.message.processor.topology.ApplicationClustersCreatedMessageProcessor} > - Cluster created: [serviceName=cartridge-proxy, > clusterId=system.cartridge-proxy.cartridge-proxy.domain, > autoscalePolicyName=economyPolicy, deploymentPolicyName=static-1, > hostNames=[system.cartridge-proxy.qmog.cisco.com], tenantRange=*, > loadBalanceAlgorithmName=null, appId=system, parentId=null, > accessUrls=null, kubernetesServices=[]] > > TID: [0] [STRATOS] [2015-03-17 09:13:00,690] INFO > {org.apache.stratos.autoscaler.monitor.component.ParentComponentMonitor} - > Starting dependent monitor: [application] system [component] > system.cartridge-proxy.cartridge-proxy.domain > > TID: [0] [STRATOS] [2015-03-17 09:13:00,691] INFO > {org.apache.stratos.autoscaler.monitor.component.ParentComponentMonitor} - > Monitor scheduled: [type] cluster [component] > system.cartridge-proxy.cartridge-proxy.domain > > TID: [0] [STRATOS] [2015-03-17 09:13:00,691] INFO > {org.apache.stratos.autoscaler.monitor.component.ParentComponentMonitor} - > Starting monitor: [type] cluster [component] > system.cartridge-proxy.cartridge-proxy.domain > > TID: [0] [STRATOS] [2015-03-17 09:13:00,691] INFO > {org.apache.stratos.autoscaler.util.AutoscalerUtil} - Monitor started > successfully: [application] system [dependents] > system.cartridge-proxy.cartridge-proxy.domain [startup-time] 0 seconds > > TID: [0] [STRATOS] [2015-03-17 09:13:00,724] INFO > {org.apache.stratos.cloud.controller.services.impl.CloudControllerServiceImpl} > - All partitions [whole-region] were validated successfully, against the > Cartridge: cartridge-proxy > > TID: [0] [STRATOS] [2015-03-17 09:13:01,078] INFO > {org.apache.stratos.cloud.controller.messaging.publisher.TopologyEventPublisher} > - Publishing cluster instance created event: [service-name] > cartridge-proxy [cluster-id] system.cartridge-proxy.cartridge-proxy.domain > in [network-partition-id] null [instance-id] system-1 > > TID: [0] [STRATOS] [2015-03-17 09:13:01,102] INFO > {org.apache.stratos.autoscaler.monitor.MonitorFactory} - ClusterMonitor > created: ClusterMonitor > [clusterId=system.cartridge-proxy.cartridge-proxy.domain, hasPrimary=false ] > > TID: [0] [STRATOS] [2015-03-17 09:13:01,103] INFO > {org.apache.stratos.autoscaler.monitor.component.ParentComponentMonitor} - > Monitor started successfully: [type] cluster [component] > system.cartridge-proxy.cartridge-proxy.domain [dependents] none > [startup-time] 0 seconds > > TID: [0] [STRATOS] [2015-03-17 09:13:01,125] INFO > {org.apache.stratos.autoscaler.event.receiver.topology.AutoscalerTopologyEventReceiver} > - Monitoring task for Cluster Monitor with cluster id > system.cartridge-proxy.cartridge-proxy.domain started successfully > > TID: [0] [STRATOS] [2015-03-17 09:13:01,131] INFO > {org.apache.stratos.autoscaler.rule.RuleLog} - [min-check] Partition > available, hence trying to spawn an instance to fulfil minimum count! > [cluster] system.cartridge-proxy.cartridge-proxy.domain > > TID: [0] [STRATOS] [2015-03-17 09:13:01,132] INFO > {org.apache.stratos.autoscaler.client.CloudControllerClient} - Trying to > spawn an instance via cloud controller: [cluster] > system.cartridge-proxy.cartridge-proxy.domain [partition] whole-region > [network-partition-id] RegionOne > > TID: [0] [STRATOS] [2015-03-17 09:13:01,150] INFO > {org.apache.stratos.cloud.controller.messaging.publisher.TopologyEventPublisher} > - Publishing member created event: [service-name] cartridge-proxy > [cluster-id] system.cartridge-proxy.cartridge-proxy.domain > [cluster-instance-id] system-1 [member-id] > system.cartridge-proxy.cartridge-proxy.domain7eac63b9-d106-42f9-95c6-ec97041062e1 > [instance-id] null [network-partition-id] RegionOne [partition-id] > whole-region [lb-cluster-id] null > > TID: [0] [STRATOS] [2015-03-17 09:13:01,159] INFO > {org.apache.stratos.messaging.message.processor.topology.MemberCreatedMessageProcessor} > - Member created: [service-name] cartridge-proxy [cluster-id] > system.cartridge-proxy.cartridge-proxy.domain [member-id] > system.cartridge-proxy.cartridge-proxy.domain7eac63b9-d106-42f9-95c6-ec97041062e1 > [cluster-instance-id] system-1 > > TID: [0] [STRATOS] [2015-03-17 09:13:11,539] INFO > {org.apache.stratos.cloud.controller.services.impl.InstanceCreator} - > Instance started successfully: [cartridge-type] cartridge-proxy > [cluster-id] system.cartridge-proxy.cartridge-proxy.domain [instance-id] > RegionOne/8ea88f5f-23be-4045-962d-c8c43eaa3596 [default-private-ip] null > [default-public-ip] null > > TID: [0] [STRATOS] [2015-03-17 09:13:11,540] INFO > {org.apache.stratos.cloud.controller.iaases.JcloudsIaas} - Allocating IP > addresses for member: [cartridge-type] cartridge-proxy [member-id] > system.cartridge-proxy.cartridge-proxy.domain7eac63b9-d106-42f9-95c6-ec97041062e1 > > TID: [0] [STRATOS] [2015-03-17 09:13:11,611] INFO > {org.apache.stratos.cloud.controller.iaases.JcloudsIaas} - Retrieving > private IP addresses MemberContext [applicationId=system, > cartridgeType=cartridge-proxy, > clusterId=system.cartridge-proxy.cartridge-proxy.domain, > memberId=system.cartridge-proxy.cartridge-proxy.domain7eac63b9-d106-42f9-95c6-ec97041062e1, > instanceId=RegionOne/8ea88f5f-23be-4045-962d-c8c43eaa3596, > partition=Partition [id=whole-region, description=null, isPublic=false, > provider=Core, properties=Properties [properties=[Property [name=region, > value=RegionOne]]]], defaultPrivateIP=172.16.180.22, defaultPublicIP=null, > allocatedIPs=null, publicIPs=[], privateIPs=[172.16.180.22], > initTime=1426583581140, lbClusterId=null, networkPartitionId=RegionOne, > kubernetesPodId=null, kubernetesPodLabel=null, loadBalancingIPType=Private, > instanceMetadata=org.apache.stratos.cloud.controller.domain.InstanceMetadata@14612b31, > properties=Properties [properties=[Property [name=PRIMARY, value=false], > Property [name=MIN_COUNT, value=1]]]] > > TID: [0] [STRATOS] [2015-03-17 09:13:11,621] INFO > {org.apache.stratos.cloud.controller.messaging.publisher.TopologyEventPublisher} > - Publishing member initialized event: [service-name] cartridge-proxy > [cluster-id] system.cartridge-proxy.cartridge-proxy.domain > [cluster-instance-id] system-1 [member-id] > system.cartridge-proxy.cartridge-proxy.domain7eac63b9-d106-42f9-95c6-ec97041062e1 > [instance-id] RegionOne/8ea88f5f-23be-4045-962d-c8c43eaa3596 > [network-partition-id] RegionOne [partition-id] whole-region > [lb-cluster-id] null > > TID: [0] [STRATOS] [2015-03-17 09:13:11,629] INFO > {org.apache.stratos.messaging.message.processor.topology.MemberInitializedMessageProcessor} > - Member initialized: [service] cartridge-proxy [cluster] > system.cartridge-proxy.cartridge-proxy.domain [member] > system.cartridge-proxy.cartridge-proxy.domain7eac63b9-d106-42f9-95c6-ec97041062e1 > > TID: [0] [STRATOS] [2015-03-17 09:15:01,579] INFO > {org.apache.stratos.manager.messaging.receiver.StratosManagerInstanceStatusEventReceiver} > - Instance started event received: [application-id] system > [cartridge-type] cartridge-proxy [member-id] > system.cartridge-proxy.cartridge-proxy.domain7eac63b9-d106-42f9-95c6-ec97041062e1 > > TID: [0] [STRATOS] [2015-03-17 09:15:01,590] INFO > {org.apache.stratos.cloud.controller.messaging.publisher.TopologyEventPublisher} > - Publishing member started event: [service-name] cartridge-proxy > [cluster-id] system.cartridge-proxy.cartridge-proxy.domain > [cluster-instance-id] system-1 [member-id] > system.cartridge-proxy.cartridge-proxy.domain7eac63b9-d106-42f9-95c6-ec97041062e1 > [network-partition-id] RegionOne [partition-id] whole-region > > TID: [0] [STRATOS] [2015-03-17 09:15:01,597] INFO > {org.apache.stratos.messaging.message.processor.topology.MemberStartedMessageProcessor} > - Member started: [service] cartridge-proxy [cluster] > system.cartridge-proxy.cartridge-proxy.domain [member] > system.cartridge-proxy.cartridge-proxy.domain7eac63b9-d106-42f9-95c6-ec97041062e1 > > TID: [0] [STRATOS] [2015-03-17 09:15:01,604] INFO > {org.apache.stratos.manager.components.ArtifactDistributionCoordinator} - > Artifact updated event published: [application-id] system [tenant-id] -1234 > [cartridge-type] cartridge-proxy [alias] cartridge-proxy [repo-url] > http://octl.qmog.cisco.com:10080/git/default.git > > TID: [0] [STRATOS] [2015-03-17 09:15:07,297] INFO > {org.apache.stratos.cloud.controller.messaging.publisher.TopologyEventPublisher} > - Publishing member activated event: [service-name] cartridge-proxy > [cluster-id] system.cartridge-proxy.cartridge-proxy.domain > [cluster-instance-id] system-1 [member-id] > system.cartridge-proxy.cartridge-proxy.domain7eac63b9-d106-42f9-95c6-ec97041062e1 > [network-partition-id] RegionOne [partition-id] whole-region > > TID: [0] [STRATOS] [2015-03-17 09:15:07,307] INFO > {org.apache.stratos.messaging.message.processor.topology.MemberActivatedMessageProcessor} > - Member activated: [service] cartridge-proxy [cluster] > system.cartridge-proxy.cartridge-proxy.domain [member] > system.cartridge-proxy.cartridge-proxy.domain7eac63b9-d106-42f9-95c6-ec97041062e1 > > TID: [0] [STRATOS] [2015-03-17 09:15:07,307] INFO > {org.apache.stratos.cep.extension.CEPTopologyEventReceiver} - Member > [member id] > system.cartridge-proxy.cartridge-proxy.domain7eac63b9-d106-42f9-95c6-ec97041062e1 > was added to the time stamp map. > > TID: [0] [STRATOS] [2015-03-17 09:15:07,308] INFO > {org.apache.stratos.autoscaler.status.processor.cluster.ClusterStatusActiveProcessor} > - Publishing cluster activated event for [application]: system [cluster]: > system.cartridge-proxy.cartridge-proxy.domain > > > > However, despite the Member activated event, the instance is still marked > as Inactive: > > > > $ ./bin/orchestration stratos-login --admin describe-application-runtime > cartridge-proxy > > Application: cartridge-proxy > > {"multiTenant":false,"status":"Inactive"} > > > > Note, between 08:46 and 09:13, I was doing other things (trying to get a > multi-VM application launched), but nothing that should have interfered > with this activity. > > > > Thanks, Shaheed > -- Imesh Gunaratne Technical Lead, WSO2 Committer & PMC Member, Apache Stratos
