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
