heat-watch set-state fails

[Masashi Nakamichi]

I try heat-cloudwatch with Folsom(2012.2.1).
I use master branch of Heat(commit 7e94df10bb9fbbd16b1f15eaac5df01b77630f1d).

First, create stack.
$ heat-cfn create autoscaling --template-file=templates/AutoScalingMultiAZSample.template --parameters="InstanceType=m1.small;DBUsername=${USER};DBPassword=password;KeyName=${USER}_key;LinuxDistribution=F17"

Second, set metric.
$ heat-watch metric-put-data autoscaling.MEMAlarmHigh system/linux MemoryUtilization Count 1
True

Third, set alarm.
$ heat-watch set-state autoscaling.MEMAlarmHigh ALARM
True

It seemed to succeed in scale-up, but following error log is output by engine.log.

(engine.log)
    :
2012-12-06 18:38:10 DEBUG [heat.openstack.common.rpc.amqp] received {u'_context_roles': u'admin,KeystoneAdmin,KeystoneServiceAdmin', u'_msg_id': u'3abf640d6fb048f0877d049dee04cda5', u'args': {u'state': u'ALARM', u'watch_name': u'autoscaling.MEMAlarmHigh'}, u'_context_password': None, u'_context_auth_url': u'http://127.0.0.1:5000/v2.0', u'_context_aws_auth_uri': u'http://localhost:5000/v2.0/ec2tokens', u'_context_service_tenant': u'service', u'_context_service_password': u'service', u'_context_aws_creds': u'{"ec2Credentials": {"access": "a79308023b3d48a4ac6fa9b8a5c32f33", "host": "127.0.0.1:8003", "verb": "GET", "params": {"SignatureVersion": "2", "AWSAccessKeyId": "a79308023b3d48a4ac6fa9b8a5c32f33", "StateValue": "ALARM", "Version": "2010-08-01", "Timestamp": "2012-12-06T09:38:10Z", "StateReason": "", "SignatureMethod": "HmacSHA256", "AlarmName": "autoscaling.MEMAlarmHigh", "Action": "SetAlarmState"}, "signature": "PRa0curzVs0A0kiQPJSw3POREHLjF6RiMXi4dQchNPw=", "path": "/v1/"}}', u'_context_service_user': u'heat', u'_context_tenant': u'admin', u'_context_auth_token': '<SANITIZED>', u'_context_is_admin': True, u'version': u'1.0', u'_context_tenant_id': u'db2e96b25cbf4bedbe3d456565fc9606', u'method': u'set_watch_state', u'_context_username': None}
2012-12-06 18:38:10 DEBUG [heat.openstack.common.rpc.amqp] unpacked context: {'username': None, 'service_user': u'heat', 'service_tenant': u'service', 'roles': u'admin,KeystoneAdmin,KeystoneServiceAdmin', 'aws_auth_uri': u'http://localhost:5000/v2.0/ec2tokens', 'tenant_id': u'db2e96b25cbf4bedbe3d456565fc9606', 'auth_token': '<SANITIZED>', 'service_password': u'service', 'auth_url': u'http://127.0.0.1:5000/v2.0', 'is_admin': True, 'password': None, 'aws_creds': u'{"ec2Credentials": {"access": "a79308023b3d48a4ac6fa9b8a5c32f33", "host": "127.0.0.1:8003", "verb": "GET", "params": {"SignatureVersion": "2", "AWSAccessKeyId": "a79308023b3d48a4ac6fa9b8a5c32f33", "StateValue": "ALARM", "Version": "2010-08-01", "Timestamp": "2012-12-06T09:38:10Z", "StateReason": "", "SignatureMethod": "HmacSHA256", "AlarmName": "autoscaling.MEMAlarmHigh", "Action": "SetAlarmState"}, "signature": "PRa0curzVs0A0kiQPJSw3POREHLjF6RiMXi4dQchNPw=", "path": "/v1/"}}', 'tenant': u'admin'}
2012-12-06 18:38:10 WARNING [heat.engine.watchrule] WATCH: stack:0f9cf00c-e921-4653-949b-9ce222c52180, watch_name:autoscaling.MEMAlarmHigh ALARM
2012-12-06 18:38:10 DEBUG [heat.engine.watchrule] Overriding state NODATA for watch autoscaling.MEMAlarmHigh with ALARM
2012-12-06 18:38:10 INFO [heat.engine.resources.autoscaling] WebServerScaleUpPolicy Alarm, adjusting Group WebServerGroup by 1
2012-12-06 18:38:10 DEBUG [heat.engine.resources.autoscaling] adjusting capacity from 1 to 2
2012-12-06 18:38:10 INFO [heat.engine.resource] creating Instance "WebServerGroup-1"
2012-12-06 18:38:10 DEBUG [keystoneclient.client] Request returned failure status: 401
2012-12-06 18:38:10 DEBUG [keystoneclient.v2_0.client] Authorization Failed.
2012-12-06 18:38:10 WARNING [heat.engine.resources.user] could not get secret for autoscaling.CfnUser Error:Unable to communicate with identity service: {"error": {"message": "The request you have made requires authentication.", "code": 401, "title": "Not Authorized"}}. (HTTP 401)
2012-12-06 18:38:10 ERROR [heat.engine.resource] DB error local variable 'kp' referenced before assignment
2012-12-06 18:38:10 DEBUG [amqplib] Closed channel #1
2012-12-06 18:38:10 DEBUG [amqplib] using channel_id: 1
2012-12-06 18:38:10 DEBUG [amqplib] Channel open
2012-12-06 18:38:10 DEBUG [novaclient.client] Using Endpoint URL: http://127.0.0.1:35357/v2.0/tokens/3935789ee578412aa098d61e2807a307?belongsTo=db2e96b25cbf4bedbe3d456565fc9606
2012-12-06 18:38:10 DEBUG [amqplib] Closed channel #1
2012-12-06 18:38:10 DEBUG [amqplib] using channel_id: 1
2012-12-06 18:38:10 DEBUG [amqplib] Channel open
2012-12-06 18:38:10 DEBUG [keystoneclient.client] Request returned failure status: 401
2012-12-06 18:38:10 DEBUG [keystoneclient.v2_0.client] Authorization Failed.
2012-12-06 18:38:10 WARNING [heat.engine.resources.user] could not get secret for autoscaling.CfnUser Error:Unable to communicate with identity service: {"error": {"message": "The request you have made requires authentication.", "code": 401, "title": "Not Authorized"}}. (HTTP 401)
2012-12-06 18:38:10 ERROR [heat.engine.resource] create Instance "WebServerGroup-1"
Traceback (most recent call last):
  File "/var/lib/folsom/heat/heat/engine/resource.py", line 219, in create
    self.handle_create()
  File "/var/lib/folsom/heat/heat/engine/resources/instance.py", line 256, in handle_create
    server_userdata = self._build_userdata(userdata)
  File "/var/lib/folsom/heat/heat/engine/resources/instance.py", line 179, in _build_userdata
    attachments.append((json.dumps(self.metadata),
  File "/var/lib/folsom/heat/heat/engine/resource.py", line 58, in __get__
    return resource.parsed_template('Metadata')
  File "/var/lib/folsom/heat/heat/engine/resource.py", line 169, in parsed_template
    return self.stack.resolve_runtime_data(template)
  File "/var/lib/folsom/heat/heat/engine/parser.py", line 424, in resolve_runtime_data
    return resolve_runtime_data(self.t, self.resources, snippet)
  File "/var/lib/folsom/heat/heat/engine/parser.py", line 453, in resolve_runtime_data
    template.resolve_base64])
  File "/var/lib/folsom/heat/heat/engine/parser.py", line 462, in transform
    data = t(data)
  File "/var/lib/folsom/heat/heat/engine/template.py", line 150, in resolve_attributes
    return _resolve(lambda k, v: k == 'Fn::GetAtt', handle_getatt, s)
  File "/var/lib/folsom/heat/heat/engine/template.py", line 228, in _resolve
    return dict((k, recurse(v)) for k, v in snippet.items())
  File "/var/lib/folsom/heat/heat/engine/template.py", line 228, in <genexpr>
    return dict((k, recurse(v)) for k, v in snippet.items())
  File "/var/lib/folsom/heat/heat/engine/template.py", line 221, in <lambda>
    recurse = lambda s: _resolve(match, handle, s)
  File "/var/lib/folsom/heat/heat/engine/template.py", line 228, in _resolve
    return dict((k, recurse(v)) for k, v in snippet.items())
  File "/var/lib/folsom/heat/heat/engine/template.py", line 228, in <genexpr>
    return dict((k, recurse(v)) for k, v in snippet.items())
  File "/var/lib/folsom/heat/heat/engine/template.py", line 221, in <lambda>
    recurse = lambda s: _resolve(match, handle, s)
  File "/var/lib/folsom/heat/heat/engine/template.py", line 228, in _resolve
    return dict((k, recurse(v)) for k, v in snippet.items())
  File "/var/lib/folsom/heat/heat/engine/template.py", line 228, in <genexpr>
    return dict((k, recurse(v)) for k, v in snippet.items())
  File "/var/lib/folsom/heat/heat/engine/template.py", line 221, in <lambda>
    recurse = lambda s: _resolve(match, handle, s)
  File "/var/lib/folsom/heat/heat/engine/template.py", line 228, in _resolve
    return dict((k, recurse(v)) for k, v in snippet.items())
  File "/var/lib/folsom/heat/heat/engine/template.py", line 228, in <genexpr>
    return dict((k, recurse(v)) for k, v in snippet.items())
  File "/var/lib/folsom/heat/heat/engine/template.py", line 221, in <lambda>
    recurse = lambda s: _resolve(match, handle, s)
  File "/var/lib/folsom/heat/heat/engine/template.py", line 228, in _resolve
    return dict((k, recurse(v)) for k, v in snippet.items())
  File "/var/lib/folsom/heat/heat/engine/template.py", line 228, in <genexpr>
    return dict((k, recurse(v)) for k, v in snippet.items())
  File "/var/lib/folsom/heat/heat/engine/template.py", line 221, in <lambda>
    recurse = lambda s: _resolve(match, handle, s)
  File "/var/lib/folsom/heat/heat/engine/template.py", line 228, in _resolve
    return dict((k, recurse(v)) for k, v in snippet.items())
  File "/var/lib/folsom/heat/heat/engine/template.py", line 228, in <genexpr>
    return dict((k, recurse(v)) for k, v in snippet.items())
  File "/var/lib/folsom/heat/heat/engine/template.py", line 221, in <lambda>
    recurse = lambda s: _resolve(match, handle, s)
  File "/var/lib/folsom/heat/heat/engine/template.py", line 230, in _resolve
    return [recurse(v) for v in snippet]
  File "/var/lib/folsom/heat/heat/engine/template.py", line 221, in <lambda>
    recurse = lambda s: _resolve(match, handle, s)
  File "/var/lib/folsom/heat/heat/engine/template.py", line 230, in _resolve
    return [recurse(v) for v in snippet]
  File "/var/lib/folsom/heat/heat/engine/template.py", line 221, in <lambda>
    recurse = lambda s: _resolve(match, handle, s)
  File "/var/lib/folsom/heat/heat/engine/template.py", line 227, in _resolve
    return handle(recurse(v))
  File "/var/lib/folsom/heat/heat/engine/template.py", line 145, in handle_getatt
    return resources[resource].FnGetAtt(att)
  File "/var/lib/folsom/heat/heat/engine/resources/user.py", line 157, in FnGetAtt
    res = self._secret_accesskey()
  File "/var/lib/folsom/heat/heat/engine/resources/user.py", line 142, in _secret_accesskey
    if kp.access == self.resource_id:
UnboundLocalError: local variable 'kp' referenced before assignment
2012-12-06 18:38:10 DEBUG [heat.engine.resources.loadbalancer] haproxy server:192.168.0.5
2012-12-06 18:38:10 WARNING [heat.engine.resources.loadbalancer] Instance (WebServerGroup-1) not found: The resource could not be found. (HTTP 404) (Request-ID: req-a0d746e5-952f-4e01-9115-839566dc55ce)
2012-12-06 18:38:10 DEBUG [heat.engine.resources.loadbalancer] haproxy server:0.0.0.0

[Masashi Nakamichi (mnakamichi)]

I changed code as follows for now.

diff --git a/heat/engine/resources/user.py b/heat/engine/resources/user.py
index d14ed46..2ab4d43 100644
--- a/heat/engine/resources/user.py
+++ b/heat/engine/resources/user.py
@@ -135,15 +135,15 @@ class AccessKey(resource.Resource):
             else:
                 try:
                     kp = self.keystone().get_ec2_keypair(user_id)
+ if kp.access == self.resource_id:
+ self._secret = kp.secret
+ else:
+ logger.error("Unexpected ec2 keypair, for %s access %s"
+ (user_id, kp.access))
                 except Exception as ex:
                     logger.warn('could not get secret for %s Error:%s' %
                                 (self.properties['UserName'],
                                  str(ex)))
- if kp.access == self.resource_id:
- self._secret = kp.secret
- else:
- logger.error("Unexpected ec2 keypair, for %s access %s" %
- (user_id, kp.access))

         return self._secret or '000-000-000'

Though 'Authorization Failed' occurred, heat-watch set-state came to be finished normally.

(engine.log)
    :
2012-12-06 18:50:06 DEBUG [heat.openstack.common.rpc.amqp] received {u'_context_roles': u'admin,KeystoneAdmin,KeystoneServiceAdmin', u'_msg_id': u'2d58da6b2cd0401fb80024cc8fcdbb0a', u'args': {u'state': u'ALARM', u'watch_name': u'autoscaling.MEMAlarmHigh'}, u'_context_password': None, u'_context_auth_url': u'http://127.0.0.1:5000/v2.0', u'_context_aws_auth_uri': u'http://localhost:5000/v2.0/ec2tokens', u'_context_service_tenant': u'service', u'_context_service_password': u'service', u'_context_aws_creds': u'{"ec2Credentials": {"access": "a79308023b3d48a4ac6fa9b8a5c32f33", "host": "127.0.0.1:8003", "verb": "GET", "params": {"SignatureVersion": "2", "AWSAccessKeyId": "a79308023b3d48a4ac6fa9b8a5c32f33", "StateValue": "ALARM", "Version": "2010-08-01", "Timestamp": "2012-12-06T09:50:05Z", "StateReason": "", "SignatureMethod": "HmacSHA256", "AlarmName": "autoscaling.MEMAlarmHigh", "Action": "SetAlarmState"}, "signature": "VqvXaeqgsWM/vsJ+JG5uC26Gy2vKm6+P9ru+/BgrEz0=", "path": "/v1/"}}', u'_context_service_user': u'heat', u'_context_tenant': u'admin', u'_context_auth_token': '<SANITIZED>', u'_context_is_admin': True, u'version': u'1.0', u'_context_tenant_id': u'db2e96b25cbf4bedbe3d456565fc9606', u'method': u'set_watch_state', u'_context_username': None}
2012-12-06 18:50:06 DEBUG [heat.openstack.common.rpc.amqp] unpacked context: {'username': None, 'service_user': u'heat', 'service_tenant': u'service', 'roles': u'admin,KeystoneAdmin,KeystoneServiceAdmin', 'aws_auth_uri': u'http://localhost:5000/v2.0/ec2tokens', 'tenant_id': u'db2e96b25cbf4bedbe3d456565fc9606', 'auth_token': '<SANITIZED>', 'service_password': u'service', 'auth_url': u'http://127.0.0.1:5000/v2.0', 'is_admin': True, 'password': None, 'aws_creds': u'{"ec2Credentials": {"access": "a79308023b3d48a4ac6fa9b8a5c32f33", "host": "127.0.0.1:8003", "verb": "GET", "params": {"SignatureVersion": "2", "AWSAccessKeyId": "a79308023b3...

[Zane Bitter (zaneb)]

I posted a patch to fix the exception handling; Steve could you look into the cause of the failure?

[Steven Hardy (shardy)]

This is probably because the user doing heat-watch set-state does not have the keystone "admin" role, which is required to add the keystone user and generate the EC2 keypair.

Admittedly handled in a pretty inelegant way, need to catch this and post a descriptive warning instead of just blowing up.

I'll do some testing to see if I can prove this and reproduce the problem above.

If possible, can you please re-test having added your keystone user to the admin role?

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/17689
Committed: http://github.com/openstack/heat/commit/0b19eea189e1eddbf1e72a8935dc7a4c42b1deeb
Submitter: Jenkins
Branch: master

commit 0b19eea189e1eddbf1e72a8935dc7a4c42b1deeb
Author: Zane Bitter <email address hidden>
Date: Fri Dec 7 17:12:41 2012 +0100

    Fix exception handling in AccessKey fetching

    bug 1087527

    Change-Id: I3de5b27e927ac18aa91f124cd5ef0333c1a83fe2
    Signed-off-by: Zane Bitter <email address hidden>