3:46 a.m.
Hello there,
I started a project where I need to deploy stacks and orchastrate them
using heat (autoscaling and so on..). I just started playing with heat and
the creation of my first stack is never complete. It stays in the status
create in progress. My log files don't say much. For my template i'm using
a veery simple one to launch a small instance.
Any ideas what that might be?
In advance, thank you for your response.
Sara
5:16 a.m.
Hi,
Can you copy your hot file and heat logs?
Kevin Tibi
Le 5 mai 2015 10:48, "ICHIBA Sara" <ichi.sara(a)gmail.com> a écrit :
Hello there,
I started a project where I need to deploy stacks and orchastrate them
using heat (autoscaling and so on..). I just started playing with heat and
the creation of my first stack is never complete. It stays in the status
create in progress. My log files don't say much. For my template i'm using
a veery simple one to launch a small instance.
Any ideas what that might be?
In advance, thank you for your response.
Sara
_______________________________________________
Rdo-list mailing list
Rdo-list(a)redhat.com
https://www.redhat.com/mailman/listinfo/rdo-list
To unsubscribe: rdo-list-unsubscribe(a)redhat.com
6:18 a.m.
hello,
here is my HOT template, it's very basic:
heat_template_version: 2013-05-23
description: Simple template to deploy a single compute instance
resources:
my_instance:
type: OS::Nova::Server
properties:
image: Cirros 0.3.3
flavor: m1.small
key_name: userkey
networks:
- network: fdf2bb77-a828-401d-969a-736a8028950f
for the logs please find them attached.
2015-05-05 12:16 GMT+02:00 Kevin Tibi <kevintibi(a)hotmail.com>:
Hi,
Can you copy your hot file and heat logs?
Kevin Tibi
Le 5 mai 2015 10:48, "ICHIBA Sara" <ichi.sara(a)gmail.com> a écrit :
> Hello there,
>
> I started a project where I need to deploy stacks and orchastrate them
> using heat (autoscaling and so on..). I just started playing with heat and
> the creation of my first stack is never complete. It stays in the status
> create in progress. My log files don't say much. For my template i'm using
> a veery simple one to launch a small instance.
>
> Any ideas what that might be?
>
> In advance, thank you for your response.
> Sara
>
> _______________________________________________
> Rdo-list mailing list
> Rdo-list(a)redhat.com
> https://www.redhat.com/mailman/listinfo/rdo-list
>
> To unsubscribe: rdo-list-unsubscribe(a)redhat.com
>
4:45 a.m.
On Tue, May 05, 2015 at 01:18:17PM +0200, ICHIBA Sara wrote:
hello,
here is my HOT template, it's very basic:
heat_template_version: 2013-05-23
description: Simple template to deploy a single compute instance
resources:
A my_instance:
A A A type: OS::Nova::Server
A A A properties:
A A A A A image: Cirros 0.3.3
A A A A A flavor: m1.small
A A A A A key_name: userkey
A A A A A networks:
A A A A A A A - network: fdf2bb77-a828-401d-969a-736a8028950f
for the logs please find them attached.
These logs are a little confusing - it looks like you failed to create the
stack due to some validation errors, then tried again and did a stack-check
and a stack resume?
Can you please set debug = True in the [DEFAULT] section of your heat.conf,
restart heat-engine and try again please?
Also, some basic checks are:
1. When the stack is CREATE_IN_PROGRESS, what does nova list show for the
instance?
2. Is it possible to boot an instance using nova boot, using the same
arguments (image, flavor, key etc) that you specify in the heat template?
I suspect that Heat is not actually the problem here, and that some part of
Nova is either misconfigured or not running, but I can't prove that without
seeing the nova CLI output and/or the nova logs.
Steve
7:08 a.m.
Actually, Nova is working I just spawned a VM with the same flavor and
image. and when I try to do the same with heat it fails. below some logs:
nova-compute.log
2015-05-07 13:58:56.208 3928 AUDIT nova.compute.manager
[req-b57bfc38-9d77-48fc-8185-474d1f9076a6 None] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Starting instance...
2015-05-07 13:58:56.376 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Attempting claim: memory 512 MB, disk
1 GB
2015-05-07 13:58:56.376 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Total memory: 3791 MB, used: 512.00 MB
2015-05-07 13:58:56.377 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] memory limit: 5686.50 MB, free:
5174.50 MB
2015-05-07 13:58:56.377 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Total disk: 13 GB, used: 0.00 GB
2015-05-07 13:58:56.378 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] disk limit not specified, defaulting
to unlimited
2015-05-07 13:58:56.395 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Claim successful
2015-05-07 13:58:56.590 3928 INFO nova.scheduler.client.report [-]
Compute_service record updated for ('localhost.localdomain',
'localhost.localdomain')
2015-05-07 13:58:56.787 3928 INFO nova.scheduler.client.report [-]
Compute_service record updated for ('localhost.localdomain',
'localhost.localdomain')
2015-05-07 13:58:57.269 3928 INFO nova.virt.libvirt.driver [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Creating image
2015-05-07 13:59:27.642 3928 INFO oslo.messaging._drivers.impl_rabbit [-]
Connecting to AMQP server on 192.168.5.33:5672
2015-05-07 13:59:27.661 3928 AUDIT nova.compute.resource_tracker [-]
Auditing locally available compute resources
2015-05-07 13:59:27.702 3928 INFO oslo.messaging._drivers.impl_rabbit [-]
Connected to AMQP server on 192.168.5.33:5672
2015-05-07 13:59:27.800 3928 INFO nova.scheduler.client.report [-]
Compute_service record updated for ('localhost.localdomain',
'localhost.localdomain')
2015-05-07 13:59:28.066 3928 AUDIT nova.compute.resource_tracker [-] Total
physical ram (MB): 3791, total allocated virtual ram (MB): 1024
2015-05-07 13:59:28.066 3928 AUDIT nova.compute.resource_tracker [-] Free
disk (GB): 12
2015-05-07 13:59:28.067 3928 AUDIT nova.compute.resource_tracker [-] Total
usable vcpus: 4, total allocated vcpus: 0
2015-05-07 13:59:28.067 3928 AUDIT nova.compute.resource_tracker [-] PCI
stats: []
2015-05-07 13:59:28.101 3928 INFO nova.scheduler.client.report [-]
Compute_service record updated for ('localhost.localdomain',
'localhost.localdomain')
2015-05-07 13:59:28.101 3928 INFO nova.compute.resource_tracker [-]
Compute_service record updated for
localhost.localdomain:localhost.localdomain
2015-05-07 13:59:47.110 3928 WARNING nova.virt.disk.vfs.guestfs [-] Failed
to close augeas aug_close: do_aug_close: you must call 'aug-init' first to
initialize Augeas
2015-05-07 13:59:51.364 3928 INFO nova.compute.manager [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] VM Started (Lifecycle Event)
2015-05-07 13:59:51.384 3928 INFO nova.virt.libvirt.driver [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Instance spawned successfully.
2015-05-07 14:00:28.264 3928 AUDIT nova.compute.resource_tracker [-]
Auditing locally available compute resources
2015-05-07 14:00:29.007 3928 AUDIT nova.compute.resource_tracker [-] Total
physical ram (MB): 3791, total allocated virtual ram (MB): 1024
2015-05-07 14:00:29.008 3928 AUDIT nova.compute.resource_tracker [-] Free
disk (GB): 12
2015-05-07 14:00:29.009 3928 AUDIT nova.compute.resource_tracker [-] Total
usable vcpus: 4, total allocated vcpus: 1
2015-05-07 14:00:29.009 3928 AUDIT nova.compute.resource_tracker [-] PCI
stats: []
2015-05-07 14:00:29.048 3928 INFO nova.scheduler.client.report [-]
Compute_service record updated for ('localhost.localdomain',
'localhost.localdomain')
2015-05-07 14:00:29.048 3928 INFO nova.compute.resource_tracker [-]
Compute_service record updated for
localhost.localdomain:localhost.localdomain
heat-engine.log
2015-05-07 14:02:45.177 3942 INFO heat.engine.service
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Creating stack
my_first_stack
2015-05-07 14:02:45.194 3942 DEBUG stevedore.extension
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
EntryPoint.parse('AWSTemplateFormatVersion.2010-09-09 =
heat.engine.cfn.template:CfnTemplate') _load_plugins
/usr/lib/python2.7/site-packages/stevedore/extension.py:156
2015-05-07 14:02:45.194 3942 DEBUG stevedore.extension
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
EntryPoint.parse('heat_template_version.2013-05-23 =
heat.engine.hot.template:HOTemplate20130523') _load_plugins
/usr/lib/python2.7/site-packages/stevedore/extension.py:156
2015-05-07 14:02:45.195 3942 DEBUG stevedore.extension
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
EntryPoint.parse('HeatTemplateFormatVersion.2012-12-12 =
heat.engine.cfn.template:HeatTemplate') _load_plugins
/usr/lib/python2.7/site-packages/stevedore/extension.py:156
2015-05-07 14:02:45.195 3942 DEBUG stevedore.extension
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
EntryPoint.parse('heat_template_version.2014-10-16 =
heat.engine.hot.template:HOTemplate20141016') _load_plugins
/usr/lib/python2.7/site-packages/stevedore/extension.py:156
2015-05-07 14:02:45.224 3942 DEBUG heat.engine.parameter_groups
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None]
<heat.engine.hot.template.HOTemplate20130523 object at 0x38d05d0> __init__
/usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:31
2015-05-07 14:02:45.225 3942 DEBUG heat.engine.parameter_groups
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None]
<heat.engine.hot.parameters.HOTParameters object at 0x3a695d0> __init__
/usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:32
2015-05-07 14:02:45.225 3942 DEBUG heat.engine.parameter_groups
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Validating Parameter
Groups. validate
/usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:43
2015-05-07 14:02:45.226 3942 DEBUG heat.engine.parameter_groups
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] ['OS::stack_id'] validate
/usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:44
2015-05-07 14:02:45.233 3942 INFO heat.engine.resource
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Validating Server
"my_instance"
2015-05-07 14:02:45.385 3942 DEBUG heat.common.keystoneclient
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Using stack domain
9ce7896d79914b68aef34d397fd3fde4 __init__
/usr/lib/python2.7/site-packages/heat/common/heat_keystoneclient.py:115
2015-05-07 14:02:45.405 3942 INFO urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection
(1): 192.168.5.33
2015-05-07 14:02:45.448 3942 DEBUG urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "GET
/v2/fac261cd98974411a9b2e977cd9ec876/os-keypairs/userkey HTTP/1.1" 200 674
_make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:45.486 3942 DEBUG glanceclient.common.http
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] curl -i -X GET -H 'User-Agent:
python-glanceclient' -H 'Content-Type: application/octet-stream' -H
'Accept-Encoding: gzip, deflate' -H 'Accept: */*' -H 'X-Auth-Token:
{SHA1}bc08e056cd78f34e9ada3dd99ceae37d33daf3f0'
http://192.168.5.33:9292/v1/images/detail?limit=20&name=cirros
log_curl_request
/usr/lib/python2.7/site-packages/glanceclient/common/http.py:122
2015-05-07 14:02:45.488 3942 INFO urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection
(1): 192.168.5.33
2015-05-07 14:02:45.770 3942 DEBUG urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "GET
/v1/images/detail?limit=20&name=cirros HTTP/1.1" 200 481 _make_request
/usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:45.771 3942 DEBUG glanceclient.common.http
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ]
HTTP/1.1 200 OK
date: Thu, 07 May 2015 12:02:45 GMT
content-length: 481
content-type: application/json; charset=UTF-8
x-openstack-request-id: req-c62b407b-0d8f-43c6-a8be-df02015dc846
{"images": [{"status": "active", "deleted_at":
null, "name": "cirros",
"deleted": false, "container_format": "bare",
"created_at":
"2015-05-06T14:27:54", "disk_format": "qcow2",
"updated_at":
"2015-05-06T15:01:15", "min_disk": 0, "protected": false,
"id":
"d80b5a24-2567-438f-89f8-b381a6716887", "min_ram": 0,
"checksum":
"133eae9fb1c98f45894a4e60d8736619", "owner":
"3740df0f18754509a252738385d375b9", "is_public": true,
"virtual_size":
null, "properties": {}, "size": 13200896}]}
log_http_response
/usr/lib/python2.7/site-packages/glanceclient/common/http.py:135
2015-05-07 14:02:46.049 3942 DEBUG keystoneclient.auth.identity.v3
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Making authentication request
to http://192.168.5.33:35357/v3/auth/tokens get_auth_ref
/usr/lib/python2.7/site-packages/keystoneclient/auth/identity/v3.py:117
2015-05-07 14:02:46.052 3942 INFO urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection
(1): 192.168.5.33
2015-05-07 14:02:46.247 3942 DEBUG urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "POST /v3/auth/tokens HTTP/1.1"
201 8275 _make_request
/usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:46.250 3942 DEBUG keystoneclient.session
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] REQ: curl -i -X POST
http://192.168.5.33:35357/v3/OS-TRUST/trusts -H "User-Agent:
python-keystoneclient" -H "Content-Type: application/json" -H
"X-Auth-Token: TOKEN_REDACTED" -d '{"trust":
{"impersonation": true,
"project_id": "fac261cd98974411a9b2e977cd9ec876",
"trustor_user_id":
"24f6dac3f1444d89884c1b1977bb0d87", "roles": [{"name":
"heat_stack_owner"}], "trustee_user_id":
"4f7e2e76441e483982fb863ed02fe63e"}}' _http_log_request
/usr/lib/python2.7/site-packages/keystoneclient/session.py:155
2015-05-07 14:02:46.252 3942 INFO urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection
(1): 192.168.5.33
2015-05-07 14:02:46.381 3942 DEBUG urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "POST /v3/OS-TRUST/trusts
HTTP/1.1" 201 717 _make_request
/usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:46.383 3942 DEBUG keystoneclient.session
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] RESP: [201] {'content-length':
'717', 'vary': 'X-Auth-Token', 'server': 'Apache/2.4.6
(CentOS)',
'connection': 'close', 'date': 'Thu, 07 May 2015 12:02:46
GMT',
'content-type': 'application/json'}
RESP BODY: {"trust": {"impersonation": true, "roles_links":
{"self": "
http://192.168.5.33:35357/v3/OS-TRUST/trusts/96e0e32b7c504d3f8f9b82fcc265...;,
"previous": null, "next": null}, "deleted_at": null,
"trustor_user_id":
"24f6dac3f1444d89884c1b1977bb0d87", "links": {"self":
"
http://192.168.5.33:35357/v3/OS-TRUST/trusts/96e0e32b7c504d3f8f9b82fcc265...,
"roles": [{"id": "cf346090e5a042ebac674bcfe14f4076",
"links": {"self": "
http://192.168.5.33:35357/v3/roles/cf346090e5a042ebac674bcfe14f4076"},
"name": "heat_stack_owner"}], "remaining_uses": null,
"expires_at": null,
"trustee_user_id": "4f7e2e76441e483982fb863ed02fe63e",
"project_id":
"fac261cd98974411a9b2e977cd9ec876", "id":
"96e0e32b7c504d3f8f9b82fcc2658e5f"}}
_http_log_response
/usr/lib/python2.7/site-packages/keystoneclient/session.py:182
2015-05-07 14:02:46.454 3942 DEBUG heat.engine.stack_lock [-] Engine
b3d3b0e1-5c47-4912-94e9-1b75159b9b10 acquired lock on stack
bb7d16c4-b73f-428d-9dbd-5b089748f374 acquire
/usr/lib/python2.7/site-packages/heat/engine/stack_lock.py:72
2015-05-07 14:02:46.456 3942 INFO oslo.messaging._drivers.impl_rabbit [-]
Connecting to AMQP server on 192.168.5.33:5672
2015-05-07 14:02:46.474 3942 DEBUG keystoneclient.auth.identity.v3 [-]
Making authentication request to http://192.168.5.33:35357/v3/auth/tokens
get_auth_ref
/usr/lib/python2.7/site-packages/keystoneclient/auth/identity/v3.py:117
2015-05-07 14:02:46.477 3942 INFO urllib3.connectionpool [-] Starting new
HTTP connection (1): 192.168.5.33
2015-05-07 14:02:46.481 3942 INFO oslo.messaging._drivers.impl_rabbit [-]
Connected to AMQP server on 192.168.5.33:5672
2015-05-07 14:02:46.666 3942 DEBUG urllib3.connectionpool [-] "POST
/v3/auth/tokens HTTP/1.1" 401 114 _make_request
/usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:46.668 3942 DEBUG keystoneclient.session [-] Request
returned failure status: 401 request
/usr/lib/python2.7/site-packages/keystoneclient/session.py:345
2015-05-07 14:02:46.668 3942 DEBUG keystoneclient.v3.client [-] Authorization
failed. get_raw_token_from_identity_service
/usr/lib/python2.7/site-packages/keystoneclient/v3/client.py:267
2015-05-07 14:02:46.673 3942 DEBUG heat.engine.stack_lock [-] Engine
b3d3b0e1-5c47-4912-94e9-1b75159b9b10 released lock on stack
bb7d16c4-b73f-428d-9dbd-5b089748f374 release
/usr/lib/python2.7/site-packages/heat/engine/stack_lock.py:122
2015-05-07 14:03:33.623 3942 INFO oslo.messaging._drivers.impl_rabbit
[req-18ad2c0b-ab52-4793-99a5-255a010d83fe ] Connecting to AMQP server on
192.168.5.33:5672
2015-05-07 14:03:33.645 3942 INFO oslo.messaging._drivers.impl_rabbit
[req-18ad2c0b-ab52-4793-99a5-255a010d83fe ] Connected to AMQP server on
192.168.5.33:5672
2015-05-07 11:45 GMT+02:00 Steven Hardy <shardy(a)redhat.com>:
On Tue, May 05, 2015 at 01:18:17PM +0200, ICHIBA Sara wrote:
> hello,
>
> here is my HOT template, it's very basic:
>
> heat_template_version: 2013-05-23
>
> description: Simple template to deploy a single compute instance
>
> resources:
> A my_instance:
> A A A type: OS::Nova::Server
> A A A properties:
> A A A A A image: Cirros 0.3.3
> A A A A A flavor: m1.small
> A A A A A key_name: userkey
> A A A A A networks:
> A A A A A A A - network: fdf2bb77-a828-401d-969a-736a8028950f
>
> for the logs please find them attached.
These logs are a little confusing - it looks like you failed to create the
stack due to some validation errors, then tried again and did a stack-check
and a stack resume?
Can you please set debug = True in the [DEFAULT] section of your heat.conf,
restart heat-engine and try again please?
Also, some basic checks are:
1. When the stack is CREATE_IN_PROGRESS, what does nova list show for the
instance?
2. Is it possible to boot an instance using nova boot, using the same
arguments (image, flavor, key etc) that you specify in the heat template?
I suspect that Heat is not actually the problem here, and that some part of
Nova is either misconfigured or not running, but I can't prove that without
seeing the nova CLI output and/or the nova logs.
Steve
7:19 a.m.
you can find the rest of heat logs attached. I launched the stack at
14:02:45.
2015-05-07 14:08 GMT+02:00 ICHIBA Sara <ichi.sara(a)gmail.com>:
Actually, Nova is working I just spawned a VM with the same flavor
and
image. and when I try to do the same with heat it fails. below some logs:
nova-compute.log
2015-05-07 13:58:56.208 3928 AUDIT nova.compute.manager
[req-b57bfc38-9d77-48fc-8185-474d1f9076a6 None] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Starting instance...
2015-05-07 13:58:56.376 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Attempting claim: memory 512 MB, disk
1 GB
2015-05-07 13:58:56.376 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Total memory: 3791 MB, used: 512.00 MB
2015-05-07 13:58:56.377 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] memory limit: 5686.50 MB, free:
5174.50 MB
2015-05-07 13:58:56.377 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Total disk: 13 GB, used: 0.00 GB
2015-05-07 13:58:56.378 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] disk limit not specified, defaulting
to unlimited
2015-05-07 13:58:56.395 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Claim successful
2015-05-07 13:58:56.590 3928 INFO nova.scheduler.client.report [-]
Compute_service record updated for ('localhost.localdomain',
'localhost.localdomain')
2015-05-07 13:58:56.787 3928 INFO nova.scheduler.client.report [-]
Compute_service record updated for ('localhost.localdomain',
'localhost.localdomain')
2015-05-07 13:58:57.269 3928 INFO nova.virt.libvirt.driver [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Creating image
2015-05-07 13:59:27.642 3928 INFO oslo.messaging._drivers.impl_rabbit [-]
Connecting to AMQP server on 192.168.5.33:5672
2015-05-07 13:59:27.661 3928 AUDIT nova.compute.resource_tracker [-]
Auditing locally available compute resources
2015-05-07 13:59:27.702 3928 INFO oslo.messaging._drivers.impl_rabbit [-]
Connected to AMQP server on 192.168.5.33:5672
2015-05-07 13:59:27.800 3928 INFO nova.scheduler.client.report [-]
Compute_service record updated for ('localhost.localdomain',
'localhost.localdomain')
2015-05-07 13:59:28.066 3928 AUDIT nova.compute.resource_tracker [-] Total
physical ram (MB): 3791, total allocated virtual ram (MB): 1024
2015-05-07 13:59:28.066 3928 AUDIT nova.compute.resource_tracker [-] Free
disk (GB): 12
2015-05-07 13:59:28.067 3928 AUDIT nova.compute.resource_tracker [-] Total
usable vcpus: 4, total allocated vcpus: 0
2015-05-07 13:59:28.067 3928 AUDIT nova.compute.resource_tracker [-] PCI
stats: []
2015-05-07 13:59:28.101 3928 INFO nova.scheduler.client.report [-]
Compute_service record updated for ('localhost.localdomain',
'localhost.localdomain')
2015-05-07 13:59:28.101 3928 INFO nova.compute.resource_tracker [-]
Compute_service record updated for
localhost.localdomain:localhost.localdomain
2015-05-07 13:59:47.110 3928 WARNING nova.virt.disk.vfs.guestfs [-] Failed
to close augeas aug_close: do_aug_close: you must call 'aug-init' first to
initialize Augeas
2015-05-07 13:59:51.364 3928 INFO nova.compute.manager [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] VM Started (Lifecycle Event)
2015-05-07 13:59:51.384 3928 INFO nova.virt.libvirt.driver [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Instance spawned successfully.
2015-05-07 14:00:28.264 3928 AUDIT nova.compute.resource_tracker [-]
Auditing locally available compute resources
2015-05-07 14:00:29.007 3928 AUDIT nova.compute.resource_tracker [-] Total
physical ram (MB): 3791, total allocated virtual ram (MB): 1024
2015-05-07 14:00:29.008 3928 AUDIT nova.compute.resource_tracker [-] Free
disk (GB): 12
2015-05-07 14:00:29.009 3928 AUDIT nova.compute.resource_tracker [-] Total
usable vcpus: 4, total allocated vcpus: 1
2015-05-07 14:00:29.009 3928 AUDIT nova.compute.resource_tracker [-] PCI
stats: []
2015-05-07 14:00:29.048 3928 INFO nova.scheduler.client.report [-]
Compute_service record updated for ('localhost.localdomain',
'localhost.localdomain')
2015-05-07 14:00:29.048 3928 INFO nova.compute.resource_tracker [-]
Compute_service record updated for
localhost.localdomain:localhost.localdomain
heat-engine.log
2015-05-07 14:02:45.177 3942 INFO heat.engine.service
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Creating stack
my_first_stack
2015-05-07 14:02:45.194 3942 DEBUG stevedore.extension
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
EntryPoint.parse('AWSTemplateFormatVersion.2010-09-09 =
heat.engine.cfn.template:CfnTemplate') _load_plugins
/usr/lib/python2.7/site-packages/stevedore/extension.py:156
2015-05-07 14:02:45.194 3942 DEBUG stevedore.extension
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
EntryPoint.parse('heat_template_version.2013-05-23 =
heat.engine.hot.template:HOTemplate20130523') _load_plugins
/usr/lib/python2.7/site-packages/stevedore/extension.py:156
2015-05-07 14:02:45.195 3942 DEBUG stevedore.extension
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
EntryPoint.parse('HeatTemplateFormatVersion.2012-12-12 =
heat.engine.cfn.template:HeatTemplate') _load_plugins
/usr/lib/python2.7/site-packages/stevedore/extension.py:156
2015-05-07 14:02:45.195 3942 DEBUG stevedore.extension
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
EntryPoint.parse('heat_template_version.2014-10-16 =
heat.engine.hot.template:HOTemplate20141016') _load_plugins
/usr/lib/python2.7/site-packages/stevedore/extension.py:156
2015-05-07 14:02:45.224 3942 DEBUG heat.engine.parameter_groups
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None]
<heat.engine.hot.template.HOTemplate20130523 object at 0x38d05d0> __init__
/usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:31
2015-05-07 14:02:45.225 3942 DEBUG heat.engine.parameter_groups
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None]
<heat.engine.hot.parameters.HOTParameters object at 0x3a695d0> __init__
/usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:32
2015-05-07 14:02:45.225 3942 DEBUG heat.engine.parameter_groups
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Validating Parameter
Groups. validate
/usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:43
2015-05-07 14:02:45.226 3942 DEBUG heat.engine.parameter_groups
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] ['OS::stack_id'] validate
/usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:44
2015-05-07 14:02:45.233 3942 INFO heat.engine.resource
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Validating Server
"my_instance"
2015-05-07 14:02:45.385 3942 DEBUG heat.common.keystoneclient
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Using stack domain
9ce7896d79914b68aef34d397fd3fde4 __init__
/usr/lib/python2.7/site-packages/heat/common/heat_keystoneclient.py:115
2015-05-07 14:02:45.405 3942 INFO urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection
(1): 192.168.5.33
2015-05-07 14:02:45.448 3942 DEBUG urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "GET
/v2/fac261cd98974411a9b2e977cd9ec876/os-keypairs/userkey HTTP/1.1" 200 674
_make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:45.486 3942 DEBUG glanceclient.common.http
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] curl -i -X GET -H 'User-Agent:
python-glanceclient' -H 'Content-Type: application/octet-stream' -H
'Accept-Encoding: gzip, deflate' -H 'Accept: */*' -H 'X-Auth-Token:
{SHA1}bc08e056cd78f34e9ada3dd99ceae37d33daf3f0'
http://192.168.5.33:9292/v1/images/detail?limit=20&name=cirros
log_curl_request
/usr/lib/python2.7/site-packages/glanceclient/common/http.py:122
2015-05-07 14:02:45.488 3942 INFO urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection
(1): 192.168.5.33
2015-05-07 14:02:45.770 3942 DEBUG urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "GET
/v1/images/detail?limit=20&name=cirros HTTP/1.1" 200 481 _make_request
/usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:45.771 3942 DEBUG glanceclient.common.http
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ]
HTTP/1.1 200 OK
date: Thu, 07 May 2015 12:02:45 GMT
content-length: 481
content-type: application/json; charset=UTF-8
x-openstack-request-id: req-c62b407b-0d8f-43c6-a8be-df02015dc846
{"images": [{"status": "active", "deleted_at":
null, "name": "cirros",
"deleted": false, "container_format": "bare",
"created_at":
"2015-05-06T14:27:54", "disk_format": "qcow2",
"updated_at":
"2015-05-06T15:01:15", "min_disk": 0, "protected": false,
"id":
"d80b5a24-2567-438f-89f8-b381a6716887", "min_ram": 0,
"checksum":
"133eae9fb1c98f45894a4e60d8736619", "owner":
"3740df0f18754509a252738385d375b9", "is_public": true,
"virtual_size":
null, "properties": {}, "size": 13200896}]}
log_http_response
/usr/lib/python2.7/site-packages/glanceclient/common/http.py:135
2015-05-07 14:02:46.049 3942 DEBUG keystoneclient.auth.identity.v3
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Making authentication request
to http://192.168.5.33:35357/v3/auth/tokens get_auth_ref
/usr/lib/python2.7/site-packages/keystoneclient/auth/identity/v3.py:117
2015-05-07 14:02:46.052 3942 INFO urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection
(1): 192.168.5.33
2015-05-07 14:02:46.247 3942 DEBUG urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "POST /v3/auth/tokens HTTP/1.1"
201 8275 _make_request
/usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:46.250 3942 DEBUG keystoneclient.session
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] REQ: curl -i -X POST
http://192.168.5.33:35357/v3/OS-TRUST/trusts -H "User-Agent:
python-keystoneclient" -H "Content-Type: application/json" -H
"X-Auth-Token: TOKEN_REDACTED" -d '{"trust":
{"impersonation": true,
"project_id": "fac261cd98974411a9b2e977cd9ec876",
"trustor_user_id":
"24f6dac3f1444d89884c1b1977bb0d87", "roles": [{"name":
"heat_stack_owner"}], "trustee_user_id":
"4f7e2e76441e483982fb863ed02fe63e"}}' _http_log_request
/usr/lib/python2.7/site-packages/keystoneclient/session.py:155
2015-05-07 14:02:46.252 3942 INFO urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection
(1): 192.168.5.33
2015-05-07 14:02:46.381 3942 DEBUG urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "POST /v3/OS-TRUST/trusts
HTTP/1.1" 201 717 _make_request
/usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:46.383 3942 DEBUG keystoneclient.session
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] RESP: [201] {'content-length':
'717', 'vary': 'X-Auth-Token', 'server':
'Apache/2.4.6 (CentOS)',
'connection': 'close', 'date': 'Thu, 07 May 2015 12:02:46
GMT',
'content-type': 'application/json'}
RESP BODY: {"trust": {"impersonation": true, "roles_links":
{"self": "
http://192.168.5.33:35357/v3/OS-TRUST/trusts/96e0e32b7c504d3f8f9b82fcc265...;,
"previous": null, "next": null}, "deleted_at": null,
"trustor_user_id":
"24f6dac3f1444d89884c1b1977bb0d87", "links": {"self":
"
http://192.168.5.33:35357/v3/OS-TRUST/trusts/96e0e32b7c504d3f8f9b82fcc265...,
"roles": [{"id": "cf346090e5a042ebac674bcfe14f4076",
"links": {"self": "
http://192.168.5.33:35357/v3/roles/cf346090e5a042ebac674bcfe14f4076"},
"name": "heat_stack_owner"}], "remaining_uses": null,
"expires_at": null,
"trustee_user_id": "4f7e2e76441e483982fb863ed02fe63e",
"project_id":
"fac261cd98974411a9b2e977cd9ec876", "id":
"96e0e32b7c504d3f8f9b82fcc2658e5f"}}
_http_log_response
/usr/lib/python2.7/site-packages/keystoneclient/session.py:182
2015-05-07 14:02:46.454 3942 DEBUG heat.engine.stack_lock [-] Engine
b3d3b0e1-5c47-4912-94e9-1b75159b9b10 acquired lock on stack
bb7d16c4-b73f-428d-9dbd-5b089748f374 acquire
/usr/lib/python2.7/site-packages/heat/engine/stack_lock.py:72
2015-05-07 14:02:46.456 3942 INFO oslo.messaging._drivers.impl_rabbit [-]
Connecting to AMQP server on 192.168.5.33:5672
2015-05-07 14:02:46.474 3942 DEBUG keystoneclient.auth.identity.v3 [-]
Making authentication request to http://192.168.5.33:35357/v3/auth/tokens
get_auth_ref
/usr/lib/python2.7/site-packages/keystoneclient/auth/identity/v3.py:117
2015-05-07 14:02:46.477 3942 INFO urllib3.connectionpool [-] Starting new
HTTP connection (1): 192.168.5.33
2015-05-07 14:02:46.481 3942 INFO oslo.messaging._drivers.impl_rabbit [-]
Connected to AMQP server on 192.168.5.33:5672
2015-05-07 14:02:46.666 3942 DEBUG urllib3.connectionpool [-] "POST
/v3/auth/tokens HTTP/1.1" 401 114 _make_request
/usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:46.668 3942 DEBUG keystoneclient.session [-] Request
returned failure status: 401 request
/usr/lib/python2.7/site-packages/keystoneclient/session.py:345
2015-05-07 14:02:46.668 3942 DEBUG keystoneclient.v3.client [-] Authorization
failed. get_raw_token_from_identity_service
/usr/lib/python2.7/site-packages/keystoneclient/v3/client.py:267
2015-05-07 14:02:46.673 3942 DEBUG heat.engine.stack_lock [-] Engine
b3d3b0e1-5c47-4912-94e9-1b75159b9b10 released lock on stack
bb7d16c4-b73f-428d-9dbd-5b089748f374 release
/usr/lib/python2.7/site-packages/heat/engine/stack_lock.py:122
2015-05-07 14:03:33.623 3942 INFO oslo.messaging._drivers.impl_rabbit
[req-18ad2c0b-ab52-4793-99a5-255a010d83fe ] Connecting to AMQP server on
192.168.5.33:5672
2015-05-07 14:03:33.645 3942 INFO oslo.messaging._drivers.impl_rabbit
[req-18ad2c0b-ab52-4793-99a5-255a010d83fe ] Connected to AMQP server on
192.168.5.33:5672
2015-05-07 11:45 GMT+02:00 Steven Hardy <shardy(a)redhat.com>:
> On Tue, May 05, 2015 at 01:18:17PM +0200, ICHIBA Sara wrote:
> > hello,
> >
> > here is my HOT template, it's very basic:
> >
> > heat_template_version: 2013-05-23
> >
> > description: Simple template to deploy a single compute instance
> >
> > resources:
> > A my_instance:
> > A A A type: OS::Nova::Server
> > A A A properties:
> > A A A A A image: Cirros 0.3.3
> > A A A A A flavor: m1.small
> > A A A A A key_name: userkey
> > A A A A A networks:
> > A A A A A A A - network: fdf2bb77-a828-401d-969a-736a8028950f
> >
> > for the logs please find them attached.
>
> These logs are a little confusing - it looks like you failed to create the
> stack due to some validation errors, then tried again and did a
> stack-check
> and a stack resume?
>
> Can you please set debug = True in the [DEFAULT] section of your
> heat.conf,
> restart heat-engine and try again please?
>
> Also, some basic checks are:
>
> 1. When the stack is CREATE_IN_PROGRESS, what does nova list show for the
> instance?
>
> 2. Is it possible to boot an instance using nova boot, using the same
> arguments (image, flavor, key etc) that you specify in the heat template?
>
> I suspect that Heat is not actually the problem here, and that some part
> of
> Nova is either misconfigured or not running, but I can't prove that
> without
> seeing the nova CLI output and/or the nova logs.
>
> Steve
>
7:26 a.m.
2015-05-07 14:08 GMT+02:00 ICHIBA Sara <ichi.sara(a)gmail.com>:
Actually, Nova is working I just spawned a VM with the same flavor
and
image. and when I try to do the same with heat it fails. below some logs:
nova-compute.log
2015-05-07 13:58:56.208 3928 AUDIT nova.compute.manager
[req-b57bfc38-9d77-48fc-8185-474d1f9076a6 None] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Starting instance...
2015-05-07 13:58:56.376 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Attempting claim: memory 512 MB, disk
1 GB
2015-05-07 13:58:56.376 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Total memory: 3791 MB, used: 512.00 MB
2015-05-07 13:58:56.377 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] memory limit: 5686.50 MB, free:
5174.50 MB
2015-05-07 13:58:56.377 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Total disk: 13 GB, used: 0.00 GB
2015-05-07 13:58:56.378 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] disk limit not specified, defaulting
to unlimited
2015-05-07 13:58:56.395 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Claim successful
2015-05-07 13:58:56.590 3928 INFO nova.scheduler.client.report [-]
Compute_service record updated for ('localhost.localdomain',
'localhost.localdomain')
2015-05-07 13:58:56.787 3928 INFO nova.scheduler.client.report [-]
Compute_service record updated for ('localhost.localdomain',
'localhost.localdomain')
2015-05-07 13:58:57.269 3928 INFO nova.virt.libvirt.driver [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Creating image
2015-05-07 13:59:27.642 3928 INFO oslo.messaging._drivers.impl_rabbit [-]
Connecting to AMQP server on 192.168.5.33:5672
2015-05-07 13:59:27.661 3928 AUDIT nova.compute.resource_tracker [-]
Auditing locally available compute resources
2015-05-07 13:59:27.702 3928 INFO oslo.messaging._drivers.impl_rabbit [-]
Connected to AMQP server on 192.168.5.33:5672
2015-05-07 13:59:27.800 3928 INFO nova.scheduler.client.report [-]
Compute_service record updated for ('localhost.localdomain',
'localhost.localdomain')
2015-05-07 13:59:28.066 3928 AUDIT nova.compute.resource_tracker [-] Total
physical ram (MB): 3791, total allocated virtual ram (MB): 1024
2015-05-07 13:59:28.066 3928 AUDIT nova.compute.resource_tracker [-] Free
disk (GB): 12
2015-05-07 13:59:28.067 3928 AUDIT nova.compute.resource_tracker [-] Total
usable vcpus: 4, total allocated vcpus: 0
2015-05-07 13:59:28.067 3928 AUDIT nova.compute.resource_tracker [-] PCI
stats: []
2015-05-07 13:59:28.101 3928 INFO nova.scheduler.client.report [-]
Compute_service record updated for ('localhost.localdomain',
'localhost.localdomain')
2015-05-07 13:59:28.101 3928 INFO nova.compute.resource_tracker [-]
Compute_service record updated for
localhost.localdomain:localhost.localdomain
2015-05-07 13:59:47.110 3928 WARNING nova.virt.disk.vfs.guestfs [-] Failed
to close augeas aug_close: do_aug_close: you must call 'aug-init' first to
initialize Augeas
2015-05-07 13:59:51.364 3928 INFO nova.compute.manager [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] VM Started (Lifecycle Event)
2015-05-07 13:59:51.384 3928 INFO nova.virt.libvirt.driver [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Instance spawned successfully.
2015-05-07 14:00:28.264 3928 AUDIT nova.compute.resource_tracker [-]
Auditing locally available compute resources
2015-05-07 14:00:29.007 3928 AUDIT nova.compute.resource_tracker [-] Total
physical ram (MB): 3791, total allocated virtual ram (MB): 1024
2015-05-07 14:00:29.008 3928 AUDIT nova.compute.resource_tracker [-] Free
disk (GB): 12
2015-05-07 14:00:29.009 3928 AUDIT nova.compute.resource_tracker [-] Total
usable vcpus: 4, total allocated vcpus: 1
2015-05-07 14:00:29.009 3928 AUDIT nova.compute.resource_tracker [-] PCI
stats: []
2015-05-07 14:00:29.048 3928 INFO nova.scheduler.client.report [-]
Compute_service record updated for ('localhost.localdomain',
'localhost.localdomain')
2015-05-07 14:00:29.048 3928 INFO nova.compute.resource_tracker [-]
Compute_service record updated for
localhost.localdomain:localhost.localdomain
heat-engine.log
2015-05-07 14:02:45.177 3942 INFO heat.engine.service
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Creating stack
my_first_stack
2015-05-07 14:02:45.194 3942 DEBUG stevedore.extension
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
EntryPoint.parse('AWSTemplateFormatVersion.2010-09-09 =
heat.engine.cfn.template:CfnTemplate') _load_plugins
/usr/lib/python2.7/site-packages/stevedore/extension.py:156
2015-05-07 14:02:45.194 3942 DEBUG stevedore.extension
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
EntryPoint.parse('heat_template_version.2013-05-23 =
heat.engine.hot.template:HOTemplate20130523') _load_plugins
/usr/lib/python2.7/site-packages/stevedore/extension.py:156
2015-05-07 14:02:45.195 3942 DEBUG stevedore.extension
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
EntryPoint.parse('HeatTemplateFormatVersion.2012-12-12 =
heat.engine.cfn.template:HeatTemplate') _load_plugins
/usr/lib/python2.7/site-packages/stevedore/extension.py:156
2015-05-07 14:02:45.195 3942 DEBUG stevedore.extension
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
EntryPoint.parse('heat_template_version.2014-10-16 =
heat.engine.hot.template:HOTemplate20141016') _load_plugins
/usr/lib/python2.7/site-packages/stevedore/extension.py:156
2015-05-07 14:02:45.224 3942 DEBUG heat.engine.parameter_groups
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None]
<heat.engine.hot.template.HOTemplate20130523 object at 0x38d05d0> __init__
/usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:31
2015-05-07 14:02:45.225 3942 DEBUG heat.engine.parameter_groups
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None]
<heat.engine.hot.parameters.HOTParameters object at 0x3a695d0> __init__
/usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:32
2015-05-07 14:02:45.225 3942 DEBUG heat.engine.parameter_groups
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Validating Parameter
Groups. validate
/usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:43
2015-05-07 14:02:45.226 3942 DEBUG heat.engine.parameter_groups
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] ['OS::stack_id'] validate
/usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:44
2015-05-07 14:02:45.233 3942 INFO heat.engine.resource
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Validating Server
"my_instance"
2015-05-07 14:02:45.385 3942 DEBUG heat.common.keystoneclient
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Using stack domain
9ce7896d79914b68aef34d397fd3fde4 __init__
/usr/lib/python2.7/site-packages/heat/common/heat_keystoneclient.py:115
2015-05-07 14:02:45.405 3942 INFO urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection
(1): 192.168.5.33
2015-05-07 14:02:45.448 3942 DEBUG urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "GET
/v2/fac261cd98974411a9b2e977cd9ec876/os-keypairs/userkey HTTP/1.1" 200 674
_make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:45.486 3942 DEBUG glanceclient.common.http
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] curl -i -X GET -H 'User-Agent:
python-glanceclient' -H 'Content-Type: application/octet-stream' -H
'Accept-Encoding: gzip, deflate' -H 'Accept: */*' -H 'X-Auth-Token:
{SHA1}bc08e056cd78f34e9ada3dd99ceae37d33daf3f0'
http://192.168.5.33:9292/v1/images/detail?limit=20&name=cirros
log_curl_request
/usr/lib/python2.7/site-packages/glanceclient/common/http.py:122
2015-05-07 14:02:45.488 3942 INFO urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection
(1): 192.168.5.33
2015-05-07 14:02:45.770 3942 DEBUG urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "GET
/v1/images/detail?limit=20&name=cirros HTTP/1.1" 200 481 _make_request
/usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:45.771 3942 DEBUG glanceclient.common.http
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ]
HTTP/1.1 200 OK
date: Thu, 07 May 2015 12:02:45 GMT
content-length: 481
content-type: application/json; charset=UTF-8
x-openstack-request-id: req-c62b407b-0d8f-43c6-a8be-df02015dc846
{"images": [{"status": "active", "deleted_at":
null, "name": "cirros",
"deleted": false, "container_format": "bare",
"created_at":
"2015-05-06T14:27:54", "disk_format": "qcow2",
"updated_at":
"2015-05-06T15:01:15", "min_disk": 0, "protected": false,
"id":
"d80b5a24-2567-438f-89f8-b381a6716887", "min_ram": 0,
"checksum":
"133eae9fb1c98f45894a4e60d8736619", "owner":
"3740df0f18754509a252738385d375b9", "is_public": true,
"virtual_size":
null, "properties": {}, "size": 13200896}]}
log_http_response
/usr/lib/python2.7/site-packages/glanceclient/common/http.py:135
2015-05-07 14:02:46.049 3942 DEBUG keystoneclient.auth.identity.v3
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Making authentication request
to http://192.168.5.33:35357/v3/auth/tokens get_auth_ref
/usr/lib/python2.7/site-packages/keystoneclient/auth/identity/v3.py:117
2015-05-07 14:02:46.052 3942 INFO urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection
(1): 192.168.5.33
2015-05-07 14:02:46.247 3942 DEBUG urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "POST /v3/auth/tokens HTTP/1.1"
201 8275 _make_request
/usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:46.250 3942 DEBUG keystoneclient.session
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] REQ: curl -i -X POST
http://192.168.5.33:35357/v3/OS-TRUST/trusts -H "User-Agent:
python-keystoneclient" -H "Content-Type: application/json" -H
"X-Auth-Token: TOKEN_REDACTED" -d '{"trust":
{"impersonation": true,
"project_id": "fac261cd98974411a9b2e977cd9ec876",
"trustor_user_id":
"24f6dac3f1444d89884c1b1977bb0d87", "roles": [{"name":
"heat_stack_owner"}], "trustee_user_id":
"4f7e2e76441e483982fb863ed02fe63e"}}' _http_log_request
/usr/lib/python2.7/site-packages/keystoneclient/session.py:155
2015-05-07 14:02:46.252 3942 INFO urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection
(1): 192.168.5.33
2015-05-07 14:02:46.381 3942 DEBUG urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "POST /v3/OS-TRUST/trusts
HTTP/1.1" 201 717 _make_request
/usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:46.383 3942 DEBUG keystoneclient.session
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] RESP: [201] {'content-length':
'717', 'vary': 'X-Auth-Token', 'server':
'Apache/2.4.6 (CentOS)',
'connection': 'close', 'date': 'Thu, 07 May 2015 12:02:46
GMT',
'content-type': 'application/json'}
RESP BODY: {"trust": {"impersonation": true, "roles_links":
{"self": "
http://192.168.5.33:35357/v3/OS-TRUST/trusts/96e0e32b7c504d3f8f9b82fcc265...;,
"previous": null, "next": null}, "deleted_at": null,
"trustor_user_id":
"24f6dac3f1444d89884c1b1977bb0d87", "links": {"self":
"
http://192.168.5.33:35357/v3/OS-TRUST/trusts/96e0e32b7c504d3f8f9b82fcc265...,
"roles": [{"id": "cf346090e5a042ebac674bcfe14f4076",
"links": {"self": "
http://192.168.5.33:35357/v3/roles/cf346090e5a042ebac674bcfe14f4076"},
"name": "heat_stack_owner"}], "remaining_uses": null,
"expires_at": null,
"trustee_user_id": "4f7e2e76441e483982fb863ed02fe63e",
"project_id":
"fac261cd98974411a9b2e977cd9ec876", "id":
"96e0e32b7c504d3f8f9b82fcc2658e5f"}}
_http_log_response
/usr/lib/python2.7/site-packages/keystoneclient/session.py:182
2015-05-07 14:02:46.454 3942 DEBUG heat.engine.stack_lock [-] Engine
b3d3b0e1-5c47-4912-94e9-1b75159b9b10 acquired lock on stack
bb7d16c4-b73f-428d-9dbd-5b089748f374 acquire
/usr/lib/python2.7/site-packages/heat/engine/stack_lock.py:72
2015-05-07 14:02:46.456 3942 INFO oslo.messaging._drivers.impl_rabbit [-]
Connecting to AMQP server on 192.168.5.33:5672
2015-05-07 14:02:46.474 3942 DEBUG keystoneclient.auth.identity.v3 [-]
Making authentication request to http://192.168.5.33:35357/v3/auth/tokens
get_auth_ref
/usr/lib/python2.7/site-packages/keystoneclient/auth/identity/v3.py:117
2015-05-07 14:02:46.477 3942 INFO urllib3.connectionpool [-] Starting new
HTTP connection (1): 192.168.5.33
2015-05-07 14:02:46.481 3942 INFO oslo.messaging._drivers.impl_rabbit [-]
Connected to AMQP server on 192.168.5.33:5672
2015-05-07 14:02:46.666 3942 DEBUG urllib3.connectionpool [-] "POST
/v3/auth/tokens HTTP/1.1" 401 114 _make_request
/usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:46.668 3942 DEBUG keystoneclient.session [-] Request
returned failure status: 401 request
/usr/lib/python2.7/site-packages/keystoneclient/session.py:345
2015-05-07 14:02:46.668 3942 DEBUG keystoneclient.v3.client [-] Authorization
failed. get_raw_token_from_identity_service
/usr/lib/python2.7/site-packages/keystoneclient/v3/client.py:267
2015-05-07 14:02:46.673 3942 DEBUG heat.engine.stack_lock [-] Engine
b3d3b0e1-5c47-4912-94e9-1b75159b9b10 released lock on stack
bb7d16c4-b73f-428d-9dbd-5b089748f374 release
/usr/lib/python2.7/site-packages/heat/engine/stack_lock.py:122
2015-05-07 14:03:33.623 3942 INFO oslo.messaging._drivers.impl_rabbit
[req-18ad2c0b-ab52-4793-99a5-255a010d83fe ] Connecting to AMQP server on
192.168.5.33:5672
2015-05-07 14:03:33.645 3942 INFO oslo.messaging._drivers.impl_rabbit
[req-18ad2c0b-ab52-4793-99a5-255a010d83fe ] Connected to AMQP server on
192.168.5.33:5672
2015-05-07 11:45 GMT+02:00 Steven Hardy <shardy(a)redhat.com>:
> On Tue, May 05, 2015 at 01:18:17PM +0200, ICHIBA Sara wrote:
> > hello,
> >
> > here is my HOT template, it's very basic:
> >
> > heat_template_version: 2013-05-23
> >
> > description: Simple template to deploy a single compute instance
> >
> > resources:
> > A my_instance:
> > A A A type: OS::Nova::Server
> > A A A properties:
> > A A A A A image: Cirros 0.3.3
> > A A A A A flavor: m1.small
> > A A A A A key_name: userkey
> > A A A A A networks:
> > A A A A A A A - network: fdf2bb77-a828-401d-969a-736a8028950f
> >
> > for the logs please find them attached.
>
> These logs are a little confusing - it looks like you failed to create the
> stack due to some validation errors, then tried again and did a
> stack-check
> and a stack resume?
>
> Can you please set debug = True in the [DEFAULT] section of your
> heat.conf,
> restart heat-engine and try again please?
>
> Also, some basic checks are:
>
> 1. When the stack is CREATE_IN_PROGRESS, what does nova list show for the
> instance?
>
> 2. Is it possible to boot an instance using nova boot, using the same
> arguments (image, flavor, key etc) that you specify in the heat template?
>
> I suspect that Heat is not actually the problem here, and that some part
> of
> Nova is either misconfigured or not running, but I can't prove that
> without
> seeing the nova CLI output and/or the nova logs.
>
> Steve
>
7:41 a.m.
I found this
https://bugs.launchpad.net/heat/+bug/1405110 . Apparently i'm not the only
one to have this problem
2015-05-07 14:26 GMT+02:00 ICHIBA Sara <ichi.sara(a)gmail.com>:
2015-05-07 14:08 GMT+02:00 ICHIBA Sara <ichi.sara(a)gmail.com>:
> Actually, Nova is working I just spawned a VM with the same flavor and
> image. and when I try to do the same with heat it fails. below some logs:
>
>
> nova-compute.log
>
> 2015-05-07 13:58:56.208 3928 AUDIT nova.compute.manager
> [req-b57bfc38-9d77-48fc-8185-474d1f9076a6 None] [instance:
> 399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Starting instance...
> 2015-05-07 13:58:56.376 3928 AUDIT nova.compute.claims [-] [instance:
> 399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Attempting claim: memory 512 MB, disk
> 1 GB
> 2015-05-07 13:58:56.376 3928 AUDIT nova.compute.claims [-] [instance:
> 399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Total memory: 3791 MB, used: 512.00 MB
> 2015-05-07 13:58:56.377 3928 AUDIT nova.compute.claims [-] [instance:
> 399c6150-2877-4c5f-865f-c7ac4c5c7ed5] memory limit: 5686.50 MB, free:
> 5174.50 MB
> 2015-05-07 13:58:56.377 3928 AUDIT nova.compute.claims [-] [instance:
> 399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Total disk: 13 GB, used: 0.00 GB
> 2015-05-07 13:58:56.378 3928 AUDIT nova.compute.claims [-] [instance:
> 399c6150-2877-4c5f-865f-c7ac4c5c7ed5] disk limit not specified, defaulting
> to unlimited
> 2015-05-07 13:58:56.395 3928 AUDIT nova.compute.claims [-] [instance:
> 399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Claim successful
> 2015-05-07 13:58:56.590 3928 INFO nova.scheduler.client.report [-]
> Compute_service record updated for ('localhost.localdomain',
> 'localhost.localdomain')
> 2015-05-07 13:58:56.787 3928 INFO nova.scheduler.client.report [-]
> Compute_service record updated for ('localhost.localdomain',
> 'localhost.localdomain')
> 2015-05-07 13:58:57.269 3928 INFO nova.virt.libvirt.driver [-] [instance:
> 399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Creating image
> 2015-05-07 13:59:27.642 3928 INFO oslo.messaging._drivers.impl_rabbit [-]
> Connecting to AMQP server on 192.168.5.33:5672
> 2015-05-07 13:59:27.661 3928 AUDIT nova.compute.resource_tracker [-]
> Auditing locally available compute resources
> 2015-05-07 13:59:27.702 3928 INFO oslo.messaging._drivers.impl_rabbit [-]
> Connected to AMQP server on 192.168.5.33:5672
> 2015-05-07 13:59:27.800 3928 INFO nova.scheduler.client.report [-]
> Compute_service record updated for ('localhost.localdomain',
> 'localhost.localdomain')
> 2015-05-07 13:59:28.066 3928 AUDIT nova.compute.resource_tracker [-]
> Total physical ram (MB): 3791, total allocated virtual ram (MB): 1024
> 2015-05-07 13:59:28.066 3928 AUDIT nova.compute.resource_tracker [-] Free
> disk (GB): 12
> 2015-05-07 13:59:28.067 3928 AUDIT nova.compute.resource_tracker [-]
> Total usable vcpus: 4, total allocated vcpus: 0
> 2015-05-07 13:59:28.067 3928 AUDIT nova.compute.resource_tracker [-] PCI
> stats: []
> 2015-05-07 13:59:28.101 3928 INFO nova.scheduler.client.report [-]
> Compute_service record updated for ('localhost.localdomain',
> 'localhost.localdomain')
> 2015-05-07 13:59:28.101 3928 INFO nova.compute.resource_tracker [-]
> Compute_service record updated for
> localhost.localdomain:localhost.localdomain
> 2015-05-07 13:59:47.110 3928 WARNING nova.virt.disk.vfs.guestfs [-]
> Failed to close augeas aug_close: do_aug_close: you must call 'aug-init'
> first to initialize Augeas
> 2015-05-07 13:59:51.364 3928 INFO nova.compute.manager [-] [instance:
> 399c6150-2877-4c5f-865f-c7ac4c5c7ed5] VM Started (Lifecycle Event)
> 2015-05-07 13:59:51.384 3928 INFO nova.virt.libvirt.driver [-] [instance:
> 399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Instance spawned successfully.
> 2015-05-07 14:00:28.264 3928 AUDIT nova.compute.resource_tracker [-]
> Auditing locally available compute resources
> 2015-05-07 14:00:29.007 3928 AUDIT nova.compute.resource_tracker [-]
> Total physical ram (MB): 3791, total allocated virtual ram (MB): 1024
> 2015-05-07 14:00:29.008 3928 AUDIT nova.compute.resource_tracker [-] Free
> disk (GB): 12
> 2015-05-07 14:00:29.009 3928 AUDIT nova.compute.resource_tracker [-]
> Total usable vcpus: 4, total allocated vcpus: 1
> 2015-05-07 14:00:29.009 3928 AUDIT nova.compute.resource_tracker [-] PCI
> stats: []
> 2015-05-07 14:00:29.048 3928 INFO nova.scheduler.client.report [-]
> Compute_service record updated for ('localhost.localdomain',
> 'localhost.localdomain')
> 2015-05-07 14:00:29.048 3928 INFO nova.compute.resource_tracker [-]
> Compute_service record updated for
> localhost.localdomain:localhost.localdomain
>
>
>
>
> heat-engine.log
>
> 2015-05-07 14:02:45.177 3942 INFO heat.engine.service
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Creating stack
> my_first_stack
> 2015-05-07 14:02:45.194 3942 DEBUG stevedore.extension
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
> EntryPoint.parse('AWSTemplateFormatVersion.2010-09-09 =
> heat.engine.cfn.template:CfnTemplate') _load_plugins
> /usr/lib/python2.7/site-packages/stevedore/extension.py:156
> 2015-05-07 14:02:45.194 3942 DEBUG stevedore.extension
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
> EntryPoint.parse('heat_template_version.2013-05-23 =
> heat.engine.hot.template:HOTemplate20130523') _load_plugins
> /usr/lib/python2.7/site-packages/stevedore/extension.py:156
> 2015-05-07 14:02:45.195 3942 DEBUG stevedore.extension
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
> EntryPoint.parse('HeatTemplateFormatVersion.2012-12-12 =
> heat.engine.cfn.template:HeatTemplate') _load_plugins
> /usr/lib/python2.7/site-packages/stevedore/extension.py:156
> 2015-05-07 14:02:45.195 3942 DEBUG stevedore.extension
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
> EntryPoint.parse('heat_template_version.2014-10-16 =
> heat.engine.hot.template:HOTemplate20141016') _load_plugins
> /usr/lib/python2.7/site-packages/stevedore/extension.py:156
> 2015-05-07 14:02:45.224 3942 DEBUG heat.engine.parameter_groups
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None]
> <heat.engine.hot.template.HOTemplate20130523 object at 0x38d05d0> __init__
> /usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:31
> 2015-05-07 14:02:45.225 3942 DEBUG heat.engine.parameter_groups
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None]
> <heat.engine.hot.parameters.HOTParameters object at 0x3a695d0> __init__
> /usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:32
> 2015-05-07 14:02:45.225 3942 DEBUG heat.engine.parameter_groups
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Validating Parameter
> Groups. validate
> /usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:43
> 2015-05-07 14:02:45.226 3942 DEBUG heat.engine.parameter_groups
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] ['OS::stack_id'] validate
> /usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:44
> 2015-05-07 14:02:45.233 3942 INFO heat.engine.resource
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Validating Server
> "my_instance"
> 2015-05-07 14:02:45.385 3942 DEBUG heat.common.keystoneclient
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Using stack domain
> 9ce7896d79914b68aef34d397fd3fde4 __init__
> /usr/lib/python2.7/site-packages/heat/common/heat_keystoneclient.py:115
> 2015-05-07 14:02:45.405 3942 INFO urllib3.connectionpool
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection
> (1): 192.168.5.33
> 2015-05-07 14:02:45.448 3942 DEBUG urllib3.connectionpool
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "GET
> /v2/fac261cd98974411a9b2e977cd9ec876/os-keypairs/userkey HTTP/1.1" 200 674
> _make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
> 2015-05-07 14:02:45.486 3942 DEBUG glanceclient.common.http
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] curl -i -X GET -H 'User-Agent:
> python-glanceclient' -H 'Content-Type: application/octet-stream' -H
> 'Accept-Encoding: gzip, deflate' -H 'Accept: */*' -H
'X-Auth-Token:
> {SHA1}bc08e056cd78f34e9ada3dd99ceae37d33daf3f0'
> http://192.168.5.33:9292/v1/images/detail?limit=20&name=cirros
> log_curl_request
> /usr/lib/python2.7/site-packages/glanceclient/common/http.py:122
> 2015-05-07 14:02:45.488 3942 INFO urllib3.connectionpool
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection
> (1): 192.168.5.33
> 2015-05-07 14:02:45.770 3942 DEBUG urllib3.connectionpool
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "GET
> /v1/images/detail?limit=20&name=cirros HTTP/1.1" 200 481 _make_request
> /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
> 2015-05-07 14:02:45.771 3942 DEBUG glanceclient.common.http
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ]
> HTTP/1.1 200 OK
> date: Thu, 07 May 2015 12:02:45 GMT
> content-length: 481
> content-type: application/json; charset=UTF-8
> x-openstack-request-id: req-c62b407b-0d8f-43c6-a8be-df02015dc846
>
> {"images": [{"status": "active",
"deleted_at": null, "name": "cirros",
> "deleted": false, "container_format": "bare",
"created_at":
> "2015-05-06T14:27:54", "disk_format": "qcow2",
"updated_at":
> "2015-05-06T15:01:15", "min_disk": 0, "protected":
false, "id":
> "d80b5a24-2567-438f-89f8-b381a6716887", "min_ram": 0,
"checksum":
> "133eae9fb1c98f45894a4e60d8736619", "owner":
> "3740df0f18754509a252738385d375b9", "is_public": true,
"virtual_size":
> null, "properties": {}, "size": 13200896}]}
> log_http_response
> /usr/lib/python2.7/site-packages/glanceclient/common/http.py:135
> 2015-05-07 14:02:46.049 3942 DEBUG keystoneclient.auth.identity.v3
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Making authentication request
> to http://192.168.5.33:35357/v3/auth/tokens get_auth_ref
> /usr/lib/python2.7/site-packages/keystoneclient/auth/identity/v3.py:117
> 2015-05-07 14:02:46.052 3942 INFO urllib3.connectionpool
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection
> (1): 192.168.5.33
> 2015-05-07 14:02:46.247 3942 DEBUG urllib3.connectionpool
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "POST /v3/auth/tokens
HTTP/1.1"
> 201 8275 _make_request
> /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
> 2015-05-07 14:02:46.250 3942 DEBUG keystoneclient.session
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] REQ: curl -i -X POST
> http://192.168.5.33:35357/v3/OS-TRUST/trusts -H "User-Agent:
> python-keystoneclient" -H "Content-Type: application/json" -H
> "X-Auth-Token: TOKEN_REDACTED" -d '{"trust":
{"impersonation": true,
> "project_id": "fac261cd98974411a9b2e977cd9ec876",
"trustor_user_id":
> "24f6dac3f1444d89884c1b1977bb0d87", "roles": [{"name":
> "heat_stack_owner"}], "trustee_user_id":
> "4f7e2e76441e483982fb863ed02fe63e"}}' _http_log_request
> /usr/lib/python2.7/site-packages/keystoneclient/session.py:155
> 2015-05-07 14:02:46.252 3942 INFO urllib3.connectionpool
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection
> (1): 192.168.5.33
> 2015-05-07 14:02:46.381 3942 DEBUG urllib3.connectionpool
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "POST /v3/OS-TRUST/trusts
> HTTP/1.1" 201 717 _make_request
> /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
> 2015-05-07 14:02:46.383 3942 DEBUG keystoneclient.session
> [req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] RESP: [201] {'content-length':
> '717', 'vary': 'X-Auth-Token', 'server':
'Apache/2.4.6 (CentOS)',
> 'connection': 'close', 'date': 'Thu, 07 May 2015 12:02:46
GMT',
> 'content-type': 'application/json'}
> RESP BODY: {"trust": {"impersonation": true,
"roles_links": {"self": "
>
http://192.168.5.33:35357/v3/OS-TRUST/trusts/96e0e32b7c504d3f8f9b82fcc265...;,
> "previous": null, "next": null}, "deleted_at": null,
"trustor_user_id":
> "24f6dac3f1444d89884c1b1977bb0d87", "links": {"self":
"
>
http://192.168.5.33:35357/v3/OS-TRUST/trusts/96e0e32b7c504d3f8f9b82fcc265...,
> "roles": [{"id": "cf346090e5a042ebac674bcfe14f4076",
"links": {"self": "
> http://192.168.5.33:35357/v3/roles/cf346090e5a042ebac674bcfe14f4076"},
> "name": "heat_stack_owner"}], "remaining_uses": null,
"expires_at": null,
> "trustee_user_id": "4f7e2e76441e483982fb863ed02fe63e",
"project_id":
> "fac261cd98974411a9b2e977cd9ec876", "id":
> "96e0e32b7c504d3f8f9b82fcc2658e5f"}}
> _http_log_response
> /usr/lib/python2.7/site-packages/keystoneclient/session.py:182
> 2015-05-07 14:02:46.454 3942 DEBUG heat.engine.stack_lock [-] Engine
> b3d3b0e1-5c47-4912-94e9-1b75159b9b10 acquired lock on stack
> bb7d16c4-b73f-428d-9dbd-5b089748f374 acquire
> /usr/lib/python2.7/site-packages/heat/engine/stack_lock.py:72
> 2015-05-07 14:02:46.456 3942 INFO oslo.messaging._drivers.impl_rabbit [-]
> Connecting to AMQP server on 192.168.5.33:5672
> 2015-05-07 14:02:46.474 3942 DEBUG keystoneclient.auth.identity.v3 [-]
> Making authentication request to http://192.168.5.33:35357/v3/auth/tokens
> get_auth_ref
> /usr/lib/python2.7/site-packages/keystoneclient/auth/identity/v3.py:117
> 2015-05-07 14:02:46.477 3942 INFO urllib3.connectionpool [-] Starting new
> HTTP connection (1): 192.168.5.33
> 2015-05-07 14:02:46.481 3942 INFO oslo.messaging._drivers.impl_rabbit [-]
> Connected to AMQP server on 192.168.5.33:5672
> 2015-05-07 14:02:46.666 3942 DEBUG urllib3.connectionpool [-] "POST
> /v3/auth/tokens HTTP/1.1" 401 114 _make_request
> /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
> 2015-05-07 14:02:46.668 3942 DEBUG keystoneclient.session [-] Request
> returned failure status: 401 request
> /usr/lib/python2.7/site-packages/keystoneclient/session.py:345
> 2015-05-07 14:02:46.668 3942 DEBUG keystoneclient.v3.client [-] Authorization
> failed. get_raw_token_from_identity_service
> /usr/lib/python2.7/site-packages/keystoneclient/v3/client.py:267
> 2015-05-07 14:02:46.673 3942 DEBUG heat.engine.stack_lock [-] Engine
> b3d3b0e1-5c47-4912-94e9-1b75159b9b10 released lock on stack
> bb7d16c4-b73f-428d-9dbd-5b089748f374 release
> /usr/lib/python2.7/site-packages/heat/engine/stack_lock.py:122
> 2015-05-07 14:03:33.623 3942 INFO oslo.messaging._drivers.impl_rabbit
> [req-18ad2c0b-ab52-4793-99a5-255a010d83fe ] Connecting to AMQP server on
> 192.168.5.33:5672
> 2015-05-07 14:03:33.645 3942 INFO oslo.messaging._drivers.impl_rabbit
> [req-18ad2c0b-ab52-4793-99a5-255a010d83fe ] Connected to AMQP server on
> 192.168.5.33:5672
>
>
>
>
>
> 2015-05-07 11:45 GMT+02:00 Steven Hardy <shardy(a)redhat.com>:
>
>> On Tue, May 05, 2015 at 01:18:17PM +0200, ICHIBA Sara wrote:
>> > hello,
>> >
>> > here is my HOT template, it's very basic:
>> >
>> > heat_template_version: 2013-05-23
>> >
>> > description: Simple template to deploy a single compute instance
>> >
>> > resources:
>> > A my_instance:
>> > A A A type: OS::Nova::Server
>> > A A A properties:
>> > A A A A A image: Cirros 0.3.3
>> > A A A A A flavor: m1.small
>> > A A A A A key_name: userkey
>> > A A A A A networks:
>> > A A A A A A A - network: fdf2bb77-a828-401d-969a-736a8028950f
>> >
>> > for the logs please find them attached.
>>
>> These logs are a little confusing - it looks like you failed to create
>> the
>> stack due to some validation errors, then tried again and did a
>> stack-check
>> and a stack resume?
>>
>> Can you please set debug = True in the [DEFAULT] section of your
>> heat.conf,
>> restart heat-engine and try again please?
>>
>> Also, some basic checks are:
>>
>> 1. When the stack is CREATE_IN_PROGRESS, what does nova list show for the
>> instance?
>>
>> 2. Is it possible to boot an instance using nova boot, using the same
>> arguments (image, flavor, key etc) that you specify in the heat template?
>>
>> I suspect that Heat is not actually the problem here, and that some part
>> of
>> Nova is either misconfigured or not running, but I can't prove that
>> without
>> seeing the nova CLI output and/or the nova logs.
>>
>> Steve
>>
>
>
6:31 p.m.
Kilo heat works in Kolla. So this must be a configuration problem.
I noticed your logs have an authentication failed issue.
Recommend filing a bug against the RDO project (under community) on bugzilla.redhat.com
Regards
-steve
From: ICHIBA Sara <ichi.sara@gmail.com<mailto:ichi.sara@gmail.com>>
Date: Thursday, May 7, 2015 at 5:41 AM
To: Steven Hardy <shardy@redhat.com<mailto:shardy@redhat.com>>,
"rdo-list@redhat.com<mailto:rdo-list@redhat.com>"
<rdo-list@redhat.com<mailto:rdo-list@redhat.com>>
Subject: Re: [Rdo-list] [heat]: stack stays interminably under the status create in
progress
I found this
https://bugs.launchpad.net/heat/+bug/1405110 . Apparently i'm not the only one to have
this problem
2015-05-07 14:26 GMT+02:00 ICHIBA Sara
<ichi.sara@gmail.com<mailto:ichi.sara@gmail.com>>:
2015-05-07 14:08 GMT+02:00 ICHIBA Sara
<ichi.sara@gmail.com<mailto:ichi.sara@gmail.com>>:
Actually, Nova is working I just spawned a VM with the same flavor and image. and when I
try to do the same with heat it fails. below some logs:
nova-compute.log
2015-05-07 13:58:56.208 3928 AUDIT nova.compute.manager
[req-b57bfc38-9d77-48fc-8185-474d1f9076a6 None] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Starting instance...
2015-05-07 13:58:56.376 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Attempting claim: memory 512 MB, disk 1 GB
2015-05-07 13:58:56.376 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Total memory: 3791 MB, used: 512.00 MB
2015-05-07 13:58:56.377 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] memory limit: 5686.50 MB, free: 5174.50 MB
2015-05-07 13:58:56.377 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Total disk: 13 GB, used: 0.00 GB
2015-05-07 13:58:56.378 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] disk limit not specified, defaulting to unlimited
2015-05-07 13:58:56.395 3928 AUDIT nova.compute.claims [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Claim successful
2015-05-07 13:58:56.590 3928 INFO nova.scheduler.client.report [-] Compute_service record
updated for ('localhost.localdomain', 'localhost.localdomain')
2015-05-07 13:58:56.787 3928 INFO nova.scheduler.client.report [-] Compute_service record
updated for ('localhost.localdomain', 'localhost.localdomain')
2015-05-07 13:58:57.269 3928 INFO nova.virt.libvirt.driver [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Creating image
2015-05-07 13:59:27.642 3928 INFO oslo.messaging._drivers.impl_rabbit [-] Connecting to
AMQP server on 192.168.5.33:5672<http://192.168.5.33:5672>
2015-05-07 13:59:27.661 3928 AUDIT nova.compute.resource_tracker [-] Auditing locally
available compute resources
2015-05-07 13:59:27.702 3928 INFO oslo.messaging._drivers.impl_rabbit [-] Connected to
AMQP server on 192.168.5.33:5672<http://192.168.5.33:5672>
2015-05-07 13:59:27.800 3928 INFO nova.scheduler.client.report [-] Compute_service record
updated for ('localhost.localdomain', 'localhost.localdomain')
2015-05-07 13:59:28.066 3928 AUDIT nova.compute.resource_tracker [-] Total physical ram
(MB): 3791, total allocated virtual ram (MB): 1024
2015-05-07 13:59:28.066 3928 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 12
2015-05-07 13:59:28.067 3928 AUDIT nova.compute.resource_tracker [-] Total usable vcpus:
4, total allocated vcpus: 0
2015-05-07 13:59:28.067 3928 AUDIT nova.compute.resource_tracker [-] PCI stats: []
2015-05-07 13:59:28.101 3928 INFO nova.scheduler.client.report [-] Compute_service record
updated for ('localhost.localdomain', 'localhost.localdomain')
2015-05-07 13:59:28.101 3928 INFO nova.compute.resource_tracker [-] Compute_service record
updated for localhost.localdomain:localhost.localdomain
2015-05-07 13:59:47.110 3928 WARNING nova.virt.disk.vfs.guestfs [-] Failed to close augeas
aug_close: do_aug_close: you must call 'aug-init' first to initialize Augeas
2015-05-07 13:59:51.364 3928 INFO nova.compute.manager [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] VM Started (Lifecycle Event)
2015-05-07 13:59:51.384 3928 INFO nova.virt.libvirt.driver [-] [instance:
399c6150-2877-4c5f-865f-c7ac4c5c7ed5] Instance spawned successfully.
2015-05-07 14:00:28.264 3928 AUDIT nova.compute.resource_tracker [-] Auditing locally
available compute resources
2015-05-07 14:00:29.007 3928 AUDIT nova.compute.resource_tracker [-] Total physical ram
(MB): 3791, total allocated virtual ram (MB): 1024
2015-05-07 14:00:29.008 3928 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 12
2015-05-07 14:00:29.009 3928 AUDIT nova.compute.resource_tracker [-] Total usable vcpus:
4, total allocated vcpus: 1
2015-05-07 14:00:29.009 3928 AUDIT nova.compute.resource_tracker [-] PCI stats: []
2015-05-07 14:00:29.048 3928 INFO nova.scheduler.client.report [-] Compute_service record
updated for ('localhost.localdomain', 'localhost.localdomain')
2015-05-07 14:00:29.048 3928 INFO nova.compute.resource_tracker [-] Compute_service record
updated for localhost.localdomain:localhost.localdomain
heat-engine.log
2015-05-07 14:02:45.177 3942 INFO heat.engine.service
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Creating stack my_first_stack
2015-05-07 14:02:45.194 3942 DEBUG stevedore.extension
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
EntryPoint.parse('AWSTemplateFormatVersion.2010-09-09 =
heat.engine.cfn.template:CfnTemplate') _load_plugins
/usr/lib/python2.7/site-packages/stevedore/extension.py:156
2015-05-07 14:02:45.194 3942 DEBUG stevedore.extension
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
EntryPoint.parse('heat_template_version.2013-05-23 =
heat.engine.hot.template:HOTemplate20130523') _load_plugins
/usr/lib/python2.7/site-packages/stevedore/extension.py:156
2015-05-07 14:02:45.195 3942 DEBUG stevedore.extension
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
EntryPoint.parse('HeatTemplateFormatVersion.2012-12-12 =
heat.engine.cfn.template:HeatTemplate') _load_plugins
/usr/lib/python2.7/site-packages/stevedore/extension.py:156
2015-05-07 14:02:45.195 3942 DEBUG stevedore.extension
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] found extension
EntryPoint.parse('heat_template_version.2014-10-16 =
heat.engine.hot.template:HOTemplate20141016') _load_plugins
/usr/lib/python2.7/site-packages/stevedore/extension.py:156
2015-05-07 14:02:45.224 3942 DEBUG heat.engine.parameter_groups
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None]
<heat.engine.hot.template.HOTemplate20130523 object at 0x38d05d0> __init__
/usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:31
2015-05-07 14:02:45.225 3942 DEBUG heat.engine.parameter_groups
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None]
<heat.engine.hot.parameters.HOTParameters object at 0x3a695d0> __init__
/usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:32
2015-05-07 14:02:45.225 3942 DEBUG heat.engine.parameter_groups
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Validating Parameter Groups. validate
/usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:43
2015-05-07 14:02:45.226 3942 DEBUG heat.engine.parameter_groups
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] ['OS::stack_id'] validate
/usr/lib/python2.7/site-packages/heat/engine/parameter_groups.py:44
2015-05-07 14:02:45.233 3942 INFO heat.engine.resource
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Validating Server "my_instance"
2015-05-07 14:02:45.385 3942 DEBUG heat.common.keystoneclient
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 None] Using stack domain
9ce7896d79914b68aef34d397fd3fde4 __init__
/usr/lib/python2.7/site-packages/heat/common/heat_keystoneclient.py:115
2015-05-07 14:02:45.405 3942 INFO urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection (1):
192.168.5.33
2015-05-07 14:02:45.448 3942 DEBUG urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "GET
/v2/fac261cd98974411a9b2e977cd9ec876/os-keypairs/userkey HTTP/1.1" 200 674
_make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:45.486 3942 DEBUG glanceclient.common.http
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] curl -i -X GET -H 'User-Agent:
python-glanceclient' -H 'Content-Type: application/octet-stream' -H
'Accept-Encoding: gzip, deflate' -H 'Accept: */*' -H 'X-Auth-Token:
{SHA1}bc08e056cd78f34e9ada3dd99ceae37d33daf3f0'
http://192.168.5.33:9292/v1/images/detail?limit=20&name=cirros log_curl_request
/usr/lib/python2.7/site-packages/glanceclient/common/http.py:122
2015-05-07 14:02:45.488 3942 INFO urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection (1):
192.168.5.33
2015-05-07 14:02:45.770 3942 DEBUG urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "GET
/v1/images/detail?limit=20&name=cirros HTTP/1.1" 200 481 _make_request
/usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:45.771 3942 DEBUG glanceclient.common.http
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ]
HTTP/1.1 200 OK
date: Thu, 07 May 2015 12:02:45 GMT
content-length: 481
content-type: application/json; charset=UTF-8
x-openstack-request-id: req-c62b407b-0d8f-43c6-a8be-df02015dc846
{"images": [{"status": "active", "deleted_at":
null, "name": "cirros", "deleted": false,
"container_format": "bare", "created_at":
"2015-05-06T14:27:54", "disk_format": "qcow2",
"updated_at": "2015-05-06T15:01:15", "min_disk": 0,
"protected": false, "id":
"d80b5a24-2567-438f-89f8-b381a6716887", "min_ram": 0,
"checksum": "133eae9fb1c98f45894a4e60d8736619", "owner":
"3740df0f18754509a252738385d375b9", "is_public": true,
"virtual_size": null, "properties": {}, "size": 13200896}]}
log_http_response /usr/lib/python2.7/site-packages/glanceclient/common/http.py:135
2015-05-07 14:02:46.049 3942 DEBUG keystoneclient.auth.identity.v3
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Making authentication request to
http://192.168.5.33:35357/v3/auth/tokens get_auth_ref
/usr/lib/python2.7/site-packages/keystoneclient/auth/identity/v3.py:117
2015-05-07 14:02:46.052 3942 INFO urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection (1):
192.168.5.33
2015-05-07 14:02:46.247 3942 DEBUG urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "POST /v3/auth/tokens HTTP/1.1" 201
8275 _make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:46.250 3942 DEBUG keystoneclient.session
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] REQ: curl -i -X POST
http://192.168.5.33:35357/v3/OS-TRUST/trusts -H "User-Agent:
python-keystoneclient" -H "Content-Type: application/json" -H
"X-Auth-Token: TOKEN_REDACTED" -d '{"trust":
{"impersonation": true, "project_id":
"fac261cd98974411a9b2e977cd9ec876", "trustor_user_id":
"24f6dac3f1444d89884c1b1977bb0d87", "roles": [{"name":
"heat_stack_owner"}], "trustee_user_id":
"4f7e2e76441e483982fb863ed02fe63e"}}' _http_log_request
/usr/lib/python2.7/site-packages/keystoneclient/session.py:155
2015-05-07 14:02:46.252 3942 INFO urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] Starting new HTTP connection (1):
192.168.5.33
2015-05-07 14:02:46.381 3942 DEBUG urllib3.connectionpool
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] "POST /v3/OS-TRUST/trusts HTTP/1.1"
201 717 _make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:46.383 3942 DEBUG keystoneclient.session
[req-6b9bcd97-7a13-4bc3-984c-470e6f5949b9 ] RESP: [201] {'content-length':
'717', 'vary': 'X-Auth-Token', 'server': 'Apache/2.4.6
(CentOS)', 'connection': 'close', 'date': 'Thu, 07 May
2015 12:02:46 GMT', 'content-type': 'application/json'}
RESP BODY: {"trust": {"impersonation": true, "roles_links":
{"self":
"http://192.168.5.33:35357/v3/OS-TRUST/trusts/96e0e32b7c504d3f8f9b82fcc2658e5f/roles",
"previous": null, "next": null}, "deleted_at": null,
"trustor_user_id": "24f6dac3f1444d89884c1b1977bb0d87",
"links": {"self":
"http://192.168.5.33:35357/v3/OS-TRUST/trusts/96e0e32b7c504d3f8f9b82fcc2658e5f"},
"roles": [{"id": "cf346090e5a042ebac674bcfe14f4076",
"links": {"self":
"http://192.168.5.33:35357/v3/roles/cf346090e5a042ebac674bcfe14f4076"},
"name": "heat_stack_owner"}], "remaining_uses": null,
"expires_at": null, "trustee_user_id":
"4f7e2e76441e483982fb863ed02fe63e", "project_id":
"fac261cd98974411a9b2e977cd9ec876", "id":
"96e0e32b7c504d3f8f9b82fcc2658e5f"}}
_http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:182
2015-05-07 14:02:46.454 3942 DEBUG heat.engine.stack_lock [-] Engine
b3d3b0e1-5c47-4912-94e9-1b75159b9b10 acquired lock on stack
bb7d16c4-b73f-428d-9dbd-5b089748f374 acquire
/usr/lib/python2.7/site-packages/heat/engine/stack_lock.py:72
2015-05-07 14:02:46.456 3942 INFO oslo.messaging._drivers.impl_rabbit [-] Connecting to
AMQP server on 192.168.5.33:5672<http://192.168.5.33:5672>
2015-05-07 14:02:46.474 3942 DEBUG keystoneclient.auth.identity.v3 [-] Making
authentication request to http://192.168.5.33:35357/v3/auth/tokens get_auth_ref
/usr/lib/python2.7/site-packages/keystoneclient/auth/identity/v3.py:117
2015-05-07 14:02:46.477 3942 INFO urllib3.connectionpool [-] Starting new HTTP connection
(1): 192.168.5.33
2015-05-07 14:02:46.481 3942 INFO oslo.messaging._drivers.impl_rabbit [-] Connected to
AMQP server on 192.168.5.33:5672<http://192.168.5.33:5672>
2015-05-07 14:02:46.666 3942 DEBUG urllib3.connectionpool [-] "POST /v3/auth/tokens
HTTP/1.1" 401 114 _make_request
/usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2015-05-07 14:02:46.668 3942 DEBUG keystoneclient.session [-] Request returned failure
status: 401 request /usr/lib/python2.7/site-packages/keystoneclient/session.py:345
2015-05-07 14:02:46.668 3942 DEBUG keystoneclient.v3.client [-] Authorization failed.
get_raw_token_from_identity_service
/usr/lib/python2.7/site-packages/keystoneclient/v3/client.py:267
2015-05-07 14:02:46.673 3942 DEBUG heat.engine.stack_lock [-] Engine
b3d3b0e1-5c47-4912-94e9-1b75159b9b10 released lock on stack
bb7d16c4-b73f-428d-9dbd-5b089748f374 release
/usr/lib/python2.7/site-packages/heat/engine/stack_lock.py:122
2015-05-07 14:03:33.623 3942 INFO oslo.messaging._drivers.impl_rabbit
[req-18ad2c0b-ab52-4793-99a5-255a010d83fe ] Connecting to AMQP server on
192.168.5.33:5672<http://192.168.5.33:5672>
2015-05-07 14:03:33.645 3942 INFO oslo.messaging._drivers.impl_rabbit
[req-18ad2c0b-ab52-4793-99a5-255a010d83fe ] Connected to AMQP server on
192.168.5.33:5672<http://192.168.5.33:5672>
2015-05-07 11:45 GMT+02:00 Steven Hardy
<shardy@redhat.com<mailto:shardy@redhat.com>>:
On Tue, May 05, 2015 at 01:18:17PM +0200, ICHIBA Sara wrote:
hello,
here is my HOT template, it's very basic:
heat_template_version: 2013-05-23
description: Simple template to deploy a single compute instance
resources:
A my_instance:
A A A type: OS::Nova::Server
A A A properties:
A A A A A image: Cirros 0.3.3
A A A A A flavor: m1.small
A A A A A key_name: userkey
A A A A A networks:
A A A A A A A - network: fdf2bb77-a828-401d-969a-736a8028950f
for the logs please find them attached.
These logs are a little confusing - it looks like you failed to create the
stack due to some validation errors, then tried again and did a stack-check
and a stack resume?
Can you please set debug = True in the [DEFAULT] section of your heat.conf,
restart heat-engine and try again please?
Also, some basic checks are:
1. When the stack is CREATE_IN_PROGRESS, what does nova list show for the
instance?
2. Is it possible to boot an instance using nova boot, using the same
arguments (image, flavor, key etc) that you specify in the heat template?
I suspect that Heat is not actually the problem here, and that some part of
Nova is either misconfigured or not running, but I can't prove that without
seeing the nova CLI output and/or the nova logs.
Steve
12:22 a.m.
Heat event-list <stack> will give you more detail on what is happening.
From: Kevin Tibi <kevintibi@hotmail.com<mailto:kevintibi@hotmail.com>>
Date: Tuesday, May 5, 2015 at 3:16 AM
To: ICHIBA Sara <ichi.sara@gmail.com<mailto:ichi.sara@gmail.com>>
Cc: "rdo-list@redhat.com<mailto:rdo-list@redhat.com>"
<rdo-list@redhat.com<mailto:rdo-list@redhat.com>>
Subject: Re: [Rdo-list] [heat]: stack stays interminably under the status create in
progress
Hi,
Can you copy your hot file and heat logs?
Kevin Tibi
Le 5 mai 2015 10:48, "ICHIBA Sara"
<ichi.sara@gmail.com<mailto:ichi.sara@gmail.com>> a écrit :
Hello there,
I started a project where I need to deploy stacks and orchastrate them using heat
(autoscaling and so on..). I just started playing with heat and the creation of my first
stack is never complete. It stays in the status create in progress. My log files don't
say much. For my template i'm using a veery simple one to launch a small instance.
Any ideas what that might be?
In advance, thank you for your response.
Sara
_______________________________________________
Rdo-list mailing list
Rdo-list@redhat.com<mailto:Rdo-list@redhat.com>
https://www.redhat.com/mailman/listinfo/rdo-list
To unsubscribe:
rdo-list-unsubscribe@redhat.com<mailto:rdo-list-unsubscribe@redhat.com>
2:58 a.m.
the heat event-list command is giving me nothing. the output is a blank
scheme
2015-05-06 7:22 GMT+02:00 Steven Dake (stdake) <stdake(a)cisco.com>:
Heat event-list <stack> will give you more detail on what is
happening.
From: Kevin Tibi <kevintibi(a)hotmail.com>
Date: Tuesday, May 5, 2015 at 3:16 AM
To: ICHIBA Sara <ichi.sara(a)gmail.com>
Cc: "rdo-list(a)redhat.com" <rdo-list(a)redhat.com>
Subject: Re: [Rdo-list] [heat]: stack stays interminably under the status
create in progress
Hi,
Can you copy your hot file and heat logs?
Kevin Tibi
Le 5 mai 2015 10:48, "ICHIBA Sara" <ichi.sara(a)gmail.com> a écrit :
> Hello there,
>
> I started a project where I need to deploy stacks and orchastrate them
> using heat (autoscaling and so on..). I just started playing with heat and
> the creation of my first stack is never complete. It stays in the status
> create in progress. My log files don't say much. For my template i'm using
> a veery simple one to launch a small instance.
>
> Any ideas what that might be?
>
> In advance, thank you for your response.
> Sara
>
> _______________________________________________
> Rdo-list mailing list
> Rdo-list(a)redhat.com
> https://www.redhat.com/mailman/listinfo/rdo-list
>
> To unsubscribe: rdo-list-unsubscribe(a)redhat.com
>
3288
days inactive
3290
days old
10 comments
4 participants
participants (4)
-
ICHIBA Sara -
Kevin Tibi -
Steven Dake (stdake) -
Steven Hardy