[STRATOS-1155] 4.1 alpha : Exception thrown when spawning an instance

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 4.1.0 Alpha
• Fix Version/s: 4.1.0
• Component/s: Cloud Controller
• Assignee: Unassigned
• Reporter: Martin Eppel
• Created: 28/Jan/15 18:57
• Updated: 17/Jul/15 09:57
• Resolved: 17/Jul/15 09:57

Description

4.1 alpha : Exception thrown when spawning an instance

I am running into the following exception using the 4.1 alpha tagged stratos code in a rather basic scenario. I attached the debug enabled wsocarbon.log, application json (cisco_sample_single_subscription.json), deployment policy (cisco_sample.json) and cartridge (cisco_sample_vm.json) .

This seems only to happen when debug logs are turned on ?!
Without debug logs another exception is thrown (which is the reason why I turned the debug on in first place, see "exception without debug turned on:, attached file wso2carbon_without_debug_turned_on.log)

Btw, the instance gets started but fails to properly initialize (I suspect because of the exception) but never gets killed or moved to obsolete state.

Exception snipplet (see also attached wso2carbon-debug.log) with debug turned on:
TID: [0] [STRATOS] [2015-01-28 18:05:02,498] DEBUG

{org.apache.stratos.cloud.controller.services.impl.CloudControllerServiceImpl} - Payload: APPLICATION_ID=cisco_sample,GROUP_NAME=null,SERVICE_NAME=cisco-sample-vm,HOST_NAME=csco_sample_cartridge.qmog.cisco.com,MULTITENANT=false,TENANT_ID=-1234,TENANT_RANGE=*,CARTRIDGE_ALIAS=csco_sample_cartridge,CLUSTER_ID=csco_sample_cartridge.cisco-sample-vm.domain,CARTRIDGE_KEY=OW8htf5FfED64WV4,DEPLOYMENT=default,APPLICATION_PATH=/var/www,REPO_URL=null,PORTS=22,PROVIDER=cisco,PUPPET_IP=PUPPET_IP,PUPPET_HOSTNAME=PUPPET_HOSTNAME,PUPPET_DNS_AVAILABLE=null,PUPPET_ENV=false,,,DEPENDENCY_CLUSTER_IDS=,TRUSTSTORE_PASSWORD=wso2carbon,SIMPLE_PROPERTY=value,QTCM_DNS_SEGMENT=,CEP_PORT=7611,MONITORING_SERVER_SECURE_PORT=0,MB_PORT=1883,MB_IP=octl.qmog.cisco.com,QTCM_NETWORK_COUNT=1,CEP_IP=octl.qmog.cisco.com,ENABLE_DATA_PUBLISHER=false,MONITORING_SERVER_IP=octl.qmog.cisco.com,MONITORING_SERVER_ADMIN_PASSWORD=xxxx,MONITORING_SERVER_ADMIN_USERNAME=xxxx,CERT_TRUSTSTORE=/opt/apache-stratos-cartridge-agent/security/client-truststore.jks,MONITORING_SERVER_PORT=0,TOKEN=eyJhbGciOiJSUzI1NiJ9.eyJleHAiOjgzNDExMTMxNCwic3ViIjoiYWRtaW4iLCJhenAiOiJvT1ZiVzBkNzlJWjFpZWJCRkF1WVMwNTJuSE1hIiwiYXBwSWQiOiJjaXNjb19zYW1wbGUiLCJhdWQiOlsib09WYlcwZDc5SVoxaWViQkZBdVlTMDUybkhNYSJdLCJpc3MiOiJodHRwczpcL1wvbG9jYWxob3N0Ojk0NDNcL29hdXRoMmVuZHBvaW50c1wvdG9rZW4iLCJpYXQiOjgzNDExMjMxNH0.X6txhcyTq1x5tRqGPSy0MAV4vqVfUnixUL9oj1q_9d1tnvhYKqx88VBuA_DBbmQ9zgRI5x1P-itB5KLNt7P4CbO3ZesEVamk0E1oF4JdT-L1xUu5QUMnHkQB1cBTMMRMaHF6EZTNayBHNi67TpceGooNVG8rrSSOoOj6WuC39tc,MEMBER_ID=csco_sample_cartridge.cisco-sample-vm.domain26605a6b-0296-4bba-b373-ecff150c9a40,INSTANCE_ID=null,CLUSTER_INSTANCE_ID=cisco_sample-1,LB_CLUSTER_ID=null,NETWORK_PARTITION_ID=N1,PARTITION_ID=RegionOne-Core,INTERNAL=false,PRIMARY=false,MIN_COUNT=1 {org.apache.stratos.cloud.controller.services.impl.CloudControllerServiceImpl}

TID: [0] [STRATOS] [2015-01-28 18:05:02,499] DEBUG

{org.apache.stratos.cloud.controller.services.impl.CloudControllerServiceImpl} - Starting the instance creator thread... {org.apache.stratos.cloud.controller.services.impl.CloudControllerServiceImpl}

TID: [0] [STRATOS] [2015-01-28 18:05:02,501] DEBUG

{org.apache.stratos.cloud.controller.messaging.topology.TopologyManager} - Write lock acquired {org.apache.stratos.cloud.controller.messaging.topology.TopologyManager}

TID: [0] [STRATOS] [2015-01-28 18:05:02,501] DEBUG

{org.apache.stratos.messaging.domain.topology.lifecycle.LifeCycleStateManager} - Lifecycle state manager initialized: [identifier] csco_sample_cartridge.cisco-sample-vm.domain26605a6b-0296-4bba-b373-ecff150c9a40 [state] Created {org.apache.stratos.messaging.domain.topology.lifecycle.LifeCycleStateManager}

TID: [0] [STRATOS] [2015-01-28 18:05:02,501] DEBUG

{org.apache.stratos.cloud.controller.messaging.topology.TopologyManager} - Write lock released {org.apache.stratos.cloud.controller.messaging.topology.TopologyManager}

TID: [0] [STRATOS] [2015-01-28 18:05:02,502] DEBUG

{org.apache.stratos.cloud.controller.iaases.JcloudsIaas} - Cloud controller is delegating request to start an instance for MemberContext [applicationId=cisco_sample, cartridgeType=cisco-sample-vm, clusterId=csco_sample_cartridge.cisco-sample-vm.domain, memberId=csco_sample_cartridge.cisco-sample-vm.domain26605a6b-0296-4bba-b373-ecff150c9a40, instanceId=null, partition=Partition [id=RegionOne-Core, description=null, isPublic=false, provider=Core, partitionMin=0, partitionMax=0, properties=Properties [properties=[Property [name=region, value=RegionOne]]]], defaultPrivateIP=null, defaultPublicIP=null, allocatedIPs=null, publicIPs=null, privateIPs=null, initTime=1422468302498, lbClusterId=null, networkPartitionId=N1, instanceMetadata=null, properties=Properties [properties=[Property [name=PRIMARY, value=false], Property [name=MIN_COUNT, value=1]]]] to jclouds {org.apache.stratos.cloud.controller.iaases.JcloudsIaas}

TID: [0] [STRATOS] [2015-01-28 18:05:02,503] ERROR

{org.apache.stratos.cloud.controller.services.impl.CloudControllerServiceImpl} - Failed to start instance: org.apache.stratos.cloud.controller.domain.InstanceContext@f58ed13 {org.apache.stratos.cloud.controller.services.impl.CloudControllerServiceImpl}

java.lang.ArrayIndexOutOfBoundsException: -1
at java.util.Vector.elementData(Vector.java:730)
at java.util.Vector.get(Vector.java:746)
at org.apache.stratos.messaging.domain.topology.lifecycle.LifeCycleStateManager.getPreviousState(LifeCycleStateManager.java:130)
at org.apache.stratos.messaging.domain.topology.lifecycle.LifeCycleStateManager.changeState(LifeCycleStateManager.java:95)
at org.apache.stratos.messaging.domain.topology.Member.setStatus(Member.java:107)
at org.apache.stratos.cloud.controller.messaging.topology.TopologyBuilder.handleMemberCreatedEvent(TopologyBuilder.java:409)
at org.apache.stratos.cloud.controller.services.impl.CloudControllerServiceImpl.startInstance(CloudControllerServiceImpl.java:408)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.apache.axis2.rpc.receivers.RPCUtil.invokeServiceClass(RPCUtil.java:212)
at org.apache.axis2.rpc.receivers.RPCMessageReceiver.invokeBusinessLogic(RPCMessageReceiver.java:117)
at org.apache.axis2.receivers.AbstractInOutMessageReceiver.invokeBusinessLogic(AbstractInOutMessageReceiver.java:40)
at org.apache.axis2.receivers.AbstractMessageReceiver.receive(AbstractMessageReceiver.java:110)
at org.apache.axis2.engine.AxisEngine.receive(AxisEngine.java:180)
at org.apache.axis2.transport.http.HTTPTransportUtils.processHTTPPostRequest(HTTPTransportUtils.java:172)
at org.apache.axis2.transport.http.AxisServlet.doPost(AxisServlet.java:146)

exception without debug turned on:
TID: [0] [STRATOS] [2015-01-28 20:41:07,273] INFO

{org.apache.stratos.messaging.message.processor.topology.MemberActivatedMessageProcessor}

- Member activated: [service] cisco-sample-vm [cluster] csco_sample_cartridge.cisco-sample-vm.domain [member] csco_sample_cartridge.cisco-sample-vm.domain033db3a1-faa5-4098-8e6b-ef46410b901f
TID: [0] [STRATOS] [2015-01-28 20:41:07,275] ERROR

{org.apache.stratos.autoscaler.event.receiver.topology.AutoscalerTopologyEventReceiver}

- Error processing event null
java.lang.NullPointerException
at org.apache.stratos.autoscaler.monitor.cluster.ClusterMonitor.handleMemberActivatedEvent(ClusterMonitor.java:1133)
at org.apache.stratos.autoscaler.event.receiver.topology.AutoscalerTopologyEventReceiver$12.onEvent(AutoscalerTopologyEventReceiver.java:392)
at org.apache.stratos.messaging.listener.EventListener.update(EventListener.java:42)
at java.util.Observable.notifyObservers(Observable.java:159)
at org.apache.stratos.messaging.event.EventObservable.notifyEventListeners(EventObservable.java:51)
at org.apache.stratos.messaging.message.processor.topology.MemberActivatedMessageProcessor.doProcess(MemberActivatedMessageProcessor.java:178)
at org.apache.stratos.messaging.message.processor.topology.MemberActivatedMessageProcessor.process(MemberActivatedMessageProcessor.java:60)
at org.apache.stratos.messaging.message.processor.topology.MemberStartedMessageProcessor.process(MemberStartedMessageProcessor.java:69)
at org.apache.stratos.messaging.message.processor.topology.MemberInitializedMessageProcessor.process(MemberInitializedMessageProcessor.java:63)
at org.apache.stratos.messaging.message.processor.topology.MemberCreatedMessageProcessor.process(MemberCreatedMessageProcessor.java:67)