These times don't match with the log above, but messages all the same. The cfn log doesn't seem to mention any errors nor the return code; the only indication of error is the second-to-last line in the engine logs. From the few hours i spent looking at this yesterday the culprit appears to be that the updated template isn't present in the raw_template table and so isn't considered part of the stack by the time the CFN signal comes in. I'm not sure I understand enough of the big picture around stack-update to dive in and fix it though.




On the instance /var/log/upstart/os-collect-config.log:

[2014-06-10 14:33:50,783] (heat-config) [INFO] Completed /var/lib/heat-config/hooks/script
[2014-06-10 14:33:50,789] (heat-config) [DEBUG] Signalling to http://10.24.0.4:8000/v1/signal/arn%3Aopenstack%3Aheat%3A%3A15a41777be7244daacd242a02b862814%3Astacks%2Ftest1%2Fd8eb8c11-81de-4ed3-81c4-87a0a8a15af0%2Fresources%2Ftest-demo-test_heat_sw_deployment?Timestamp=2014-06-10T14%3A33%3A15Z&SignatureMethod=HmacSHA256&AWSAccessKeyId=538c7f0cb61140d998e04c62647124e1&SignatureVersion=2&Signature=pjub03wXQoSlYjT9gYZkNu0ntFGLtsCMm04REsp3mLU%3D with {"deploy_stdout": "Testing me some heat software config\n", "deploy_stderr": "", "deploy_status_code": 0}
[2014-06-10 14:33:51,254] (heat-config) [DEBUG] Response <Response [400]> 
dib-run-parts Tue Jun 10 14:33:51 UTC 2014 55-heat-config completed



h-eng:

2014-06-10 14:33:51.087 DEBUG heat.openstack.common.rpc.amqp  received {u'_msg_id': u'4829fe8f22f64569a3538a776b8f8439', u'_context_request_id': u'req-928bfa9b-16d6-4b27-bf72-74cafe1bb78e', u'_context_trust_id': None, u'_context_auth_token': '<SANITIZED>', u'_context_user_id': u'f53f6d31c4a0422a845a5b4d4400d5a9', u'_context_username': None, u'_reply_q': u'reply_c499de3c7e8f442686a2288c5a994a90', u'_context_show_deleted': False, u'namespace': None, u'_context_is_admin': False, u'version': u'1.0', u'_context_user': None, u'method': u'resource_signal', u'_context_roles': [u'heat_stack_user'], u'_context_auth_url': u'http://10.24.0.4:5000/v2.0', u'args': {u'resource_name': u'test-demo-test_heat_sw_deployment', u'details': {u'deploy_stdout': u'Testing me some heat software config\n', u'deploy_stderr': u'', u'deploy_status_code': 0}, u'stack_identity': {u'stack_name': u'test1', u'stack_id': u'd8eb8c11-81de-4ed3-81c4-87a0a8a15af0', u'tenant': u'15a41777be7244daacd242a02b862814', u'path': u''}}, u'_unique_id': u'd8a291698bd9403f93446c85bc8c702f', u'_context_tenant_id': u'7b0358237da24700b8a750544a25cd1c', u'_context_password': '<SANITIZED>', u'_context_trustor_user_id': None, u'_context_aws_creds': u'{"ec2Credentials": {"access": "538c7f0cb61140d998e04c62647124e1", "signature": "pjub03wXQoSlYjT9gYZkNu0ntFGLtsCMm04REsp3mLU="}}', u'_context_tenant': u'15a41777be7244daacd242a02b862814-d8eb8c11-81de-4ed3-81c4-87a0a8a'} from (pid=16255) _safe_log /opt/stack/heat/heat/openstack/common/rpc/common.py:280
2014-06-10 14:33:51.087 DEBUG heat.openstack.common.rpc.amqp  unpacked context: {'username': None, 'user_id': u'f53f6d31c4a0422a845a5b4d4400d5a9', 'show_deleted': False, 'roles': [u'heat_stack_user'], 'tenant_id': u'7b0358237da24700b8a750544a25cd1c', 'auth_token': '<SANITIZED>', 'trust_id': None, 'is_admin': False, 'user': None, 'request_id': u'req-928bfa9b-16d6-4b27-bf72-74cafe1bb78e', 'auth_url': u'http://10.24.0.4:5000/v2.0', 'password': '<SANITIZED>', 'aws_creds': u'{"ec2Credentials": {"access": "538c7f0cb61140d998e04c62647124e1", "signature": "pjub03wXQoSlYjT9gYZkNu0ntFGLtsCMm04REsp3mLU="}}', 'tenant': u'15a41777be7244daacd242a02b862814-d8eb8c11-81de-4ed3-81c4-87a0a8a', 'trustor_user_id': None} from (pid=16255) _safe_log /opt/stack/heat/heat/openstack/common/rpc/common.py:280
2014-06-10 14:33:51.095 DEBUG heat.openstack.common.policy req-f341e7a2-e528-4d5f-86aa-338c44c8f6de None smclellan  Rule context_is_admin will be now enforced from (pid=16255) enforce /opt/stack/heat/heat/openstack/common/policy.py:288
2014-06-10 14:33:51.095 DEBUG heat.openstack.common.fileutils req-f341e7a2-e528-4d5f-86aa-338c44c8f6de None smclellan  Reloading cached file /etc/heat/policy.json from (pid=16255) read_cached_file /opt/stack/heat/heat/openstack/common/fileutils.py:61
2014-06-10 14:33:51.096 DEBUG heat.openstack.common.policy req-f341e7a2-e528-4d5f-86aa-338c44c8f6de None smclellan  Rules successfully reloaded from (pid=16255) load_rules /opt/stack/heat/heat/openstack/common/policy.py:242

<< SNIP SUCCESSFUL KEYSTONE AUTH REQUEST AND RESPONSE >>

2014-06-10 14:33:51.218 DEBUG heat.openstack.common.rpc.amqp req-f341e7a2-e528-4d5f-86aa-338c44c8f6de None smclellan  Expected exception during message handling (The Resource (test-demo-test_heat_sw_deployment) could not be found in Stack test1.) from (pid=16255) _process_data /opt/stack/heat/heat/openstack/common/rpc/amqp.py:473

2014-06-10 14:33:51.219 DEBUG heat.openstack.common.rpc.amqp req-f341e7a2-e528-4d5f-86aa-338c44c8f6de None smclellan  UNIQUE_ID is 30bfbaaaefee441eaaf7ed8e1ff9ab35. from (pid=16255) _add_unique_id /opt/stack/heat/heat/openstack/common/rpc/amqp.py:342
2014-06-10 14:33:51.220 DEBUG amqp req-f341e7a2-e528-4d5f-86aa-338c44c8f6de None smclellan  Closed channel #1 from (pid=16255) _do_close /usr/local/lib/python2.7/dist-packages/amqp/channel.py:104



heat-cfn:

2014-06-10 14:33:51.082 DEBUG routes.middleware req-928bfa9b-16d6-4b27-bf72-74cafe1bb78e None 15a41777be7244daacd242a02b862814-d8eb8c11-81de-4ed3-81c4-87a0a8a  Matched POST /signal/arn:openstack:heat::15a41777be7244daacd242a02b862814:stacks/test1/d8eb8c11-81de-4ed3-81c4-87a0a8a15af0/resources/test-demo-test_heat_sw_deployment from (pid=22051) __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
2014-06-10 14:33:51.082 DEBUG routes.middleware req-928bfa9b-16d6-4b27-bf72-74cafe1bb78e None 15a41777be7244daacd242a02b862814-d8eb8c11-81de-4ed3-81c4-87a0a8a  Route path: '/signal/{arn:.*}', defaults: {'action': u'signal', 'controller': <heat.common.wsgi.Resource object at 0x2faa050>} from (pid=22051) __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
2014-06-10 14:33:51.082 DEBUG routes.middleware req-928bfa9b-16d6-4b27-bf72-74cafe1bb78e None 15a41777be7244daacd242a02b862814-d8eb8c11-81de-4ed3-81c4-87a0a8a  Match dict: {'action': u'signal', 'controller': <heat.common.wsgi.Resource object at 0x2faa050>, 'arn': u'arn:openstack:heat::15a41777be7244daacd242a02b862814:stacks/test1/d8eb8c11-81de-4ed3-81c4-87a0a8a15af0/resources/test-demo-test_heat_sw_deployment'} from (pid=22051) __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
2014-06-10 14:33:51.083 DEBUG heat.openstack.common.rpc.amqp req-928bfa9b-16d6-4b27-bf72-74cafe1bb78e None 15a41777be7244daacd242a02b862814-d8eb8c11-81de-4ed3-81c4-87a0a8a  Making synchronous call on engine ... from (pid=22051) multicall /opt/stack/heat/heat/openstack/common/rpc/amqp.py:554
2014-06-10 14:33:51.084 DEBUG heat.openstack.common.rpc.amqp req-928bfa9b-16d6-4b27-bf72-74cafe1bb78e None 15a41777be7244daacd242a02b862814-d8eb8c11-81de-4ed3-81c4-87a0a8a  MSG_ID is 4829fe8f22f64569a3538a776b8f8439 from (pid=22051) multicall /opt/stack/heat/heat/openstack/common/rpc/amqp.py:557
2014-06-10 14:33:51.084 DEBUG heat.openstack.common.rpc.amqp req-928bfa9b-16d6-4b27-bf72-74cafe1bb78e None 15a41777be7244daacd242a02b862814-d8eb8c11-81de-4ed3-81c4-87a0a8a  UNIQUE_ID is d8a291698bd9403f93446c85bc8c702f. from (pid=22051) _add_unique_id /opt/stack/heat/heat/openstack/common/rpc/amqp.py:342
2014-06-10 14:33:51.086 DEBUG amqp req-928bfa9b-16d6-4b27-bf72-74cafe1bb78e None 15a41777be7244daacd242a02b862814-d8eb8c11-81de-4ed3-81c4-87a0a8a  Closed channel #1 from (pid=22051) _do_close /usr/local/lib/python2.7/dist-packages/amqp/channel.py:104
2014-06-10 14:33:51.087 DEBUG amqp req-928bfa9b-16d6-4b27-bf72-74cafe1bb78e None 15a41777be7244daacd242a02b862814-d8eb8c11-81de-4ed3-81c4-87a0a8a  using channel_id: 1 from (pid=22051) __init__ /usr/local/lib/python2.7/dist-packages/amqp/channel.py:80
2014-06-10 14:33:51.087 DEBUG amqp req-928bfa9b-16d6-4b27-bf72-74cafe1bb78e None 15a41777be7244daacd242a02b862814-d8eb8c11-81de-4ed3-81c4-87a0a8a  Channel open from (pid=22051) _open_ok /usr/local/lib/python2.7/dist-packages/amqp/channel.py:438