Problem on running "nova boot myserver"

Thu Aug 2 13:44:39 UTC 2012

Hi Derek and all,

- snip -

> This is weird, virsh list returned no running vm's but yet something
> replied to your ssh attempt. I have seen this happen before, when
> multiple Openstack installations were running on the same local network
> and shared them same private network. Is there another openstack setup
> on the same network?
> 
> this wouldn't answer the question of why the instance failed to start in
> the first place. can you tail the log files in /var/log/nova/*log
> to see if any problems show up while you start another instance

I have another 3 openstacks installed on other VMs running Ubuntu 12.04 as OS.  But they are NOT running at the same time.  I use them for testing ONLY.

While Fedora 17 is in running they are NOT started.

>>  tail -f /var/log/nova/*log

$ tail -f /var/log/nova/*log
==> /var/log/nova/api.log <==
2012-08-02 21:31:01 AUDIT nova.api.openstack.extensions [-] Loaded extension: virtual_interfaces
2012-08-02 21:31:01 AUDIT nova.api.openstack.extensions [-] Loaded extension: os-flavor-manage
2012-08-02 21:31:01 AUDIT nova.api.openstack.extensions [-] Loaded extension: os-admin-actions
2012-08-02 21:31:01 AUDIT nova.api.openstack.extensions [-] Loaded extension: os-certificates
2012-08-02 21:31:01 AUDIT nova.api.openstack.extensions [-] Loaded extension: os-volumes
2012-08-02 21:31:01 AUDIT nova.api.openstack.volume.extensions [-] Initializing extension manager.
2012-08-02 21:31:02 INFO nova.wsgi [-] Started ec2 on 0.0.0.0:8773
2012-08-02 21:31:02 INFO nova.wsgi [-] Started osapi_compute on 0.0.0.0:8774
2012-08-02 21:31:02 INFO nova.wsgi [-] Started osapi_volume on 0.0.0.0:8776
2012-08-02 21:31:03 INFO nova.wsgi [-] Started metadata on 0.0.0.0:8775

==> /var/log/nova/cert.log <==
Command: sh /usr/lib/python2.7/site-packages/nova/CA/genrootca.sh
Exit code: 1
Stdout: ''
Stderr: "cp: cannot create regular file `openssl.cnf': Permission denied\nsed: can't read openssl.cnf: No such file or directory\nerror on line -1 of ./openssl.cnf\n140509211051872:error:02001002:system library:fopen:No such file or directory:bss_file.c:169:fopen('./openssl.cnf','rb')\n140509211051872:error:2006D080:BIO routines:BIO_new_file:no such file:bss_file.c:172:\n140509211051872:error:0E078072:configuration file routines:DEF_LOAD:no such file:conf_def.c:197:\ntouch: cannot touch `index.txt': Permission denied\n/usr/lib/python2.7/site-packages/nova/CA/genrootca.sh: line 28: serial: Permission denied\nUsing configuration from ./openssl.cnf\nerror loading the config file './openssl.cnf'\n140599705130848:error:02001002:system library:fopen:No such file or directory:bss_file.c:169:fopen('./openssl.cnf','rb')\n140599705130848:error:2006D080:BIO routines:BIO_new_file:no such file:bss_file.c:172:\n140599705130848:error:0E078072:configuration file
 routines:DEF_LOAD:no such file:conf_def.c:197:\n"
2012-08-02 21:30:56 AUDIT nova.service [-] Starting cert node (version 2012.1.1-LOCALBRANCH:LOCALREVISION)
2012-08-02 21:30:57 CRITICAL nova [-] Unexpected error while running command.
Command: sh /usr/lib/python2.7/site-packages/nova/CA/genrootca.sh
Exit code: 1
Stdout: ''
Stderr: "cp: cannot create regular file `openssl.cnf': Permission denied\nsed: can't read openssl.cnf: No such file or directory\nerror on line -1 of ./openssl.cnf\n139858879027040:error:02001002:system library:fopen:No such file or directory:bss_file.c:169:fopen('./openssl.cnf','rb')\n139858879027040:error:2006D080:BIO routines:BIO_new_file:no such file:bss_file.c:172:\n139858879027040:error:0E078072:configuration file routines:DEF_LOAD:no such file:conf_def.c:197:\ntouch: cannot touch `index.txt': Permission denied\n/usr/lib/python2.7/site-packages/nova/CA/genrootca.sh: line 28: serial: Permission denied\nUsing configuration from ./openssl.cnf\nerror loading the config file './openssl.cnf'\n140352122591072:error:02001002:system library:fopen:No such file or directory:bss_file.c:169:fopen('./openssl.cnf','rb')\n140352122591072:error:2006D080:BIO routines:BIO_new_file:no such file:bss_file.c:172:\n140352122591072:error:0E078072:configuration file
 routines:DEF_LOAD:no such file:conf_def.c:197:\n"

==> /var/log/nova/compute.log <==
2012-08-02 00:36:35 INFO nova.compute.manager [-] Updating host status
2012-08-02 00:37:38 INFO nova.virt.libvirt.connection [-] Compute_service record updated for fedora00 
2012-08-02 21:30:59 AUDIT nova.service [-] Starting compute node (version 2012.1.1-LOCALBRANCH:LOCALREVISION)
2012-08-02 21:31:04 INFO nova.virt.libvirt.connection [-] Compute_service record updated for fedora00 
2012-08-02 21:31:04 INFO nova.rpc.impl_qpid [-] Connected to AMQP server on localhost:5672
2012-08-02 21:32:04 INFO nova.compute.manager [req-ea459b38-9aa3-44e5-8618-8ddbba19160d None None] Updating bandwidth usage cache
2012-08-02 21:32:06 INFO nova.virt.libvirt.connection [req-ea459b38-9aa3-44e5-8618-8ddbba19160d None None] Compute_service record updated for fedora00 
2012-08-02 21:32:06 INFO nova.compute.manager [req-ea459b38-9aa3-44e5-8618-8ddbba19160d None None] Updating host status
2012-08-02 21:33:09 INFO nova.rpc.impl_qpid [-] Connected to AMQP server on localhost:5672
2012-08-02 21:33:10 INFO nova.virt.libvirt.connection [-] Compute_service record updated for fedora00 

==> /var/log/nova/network.log <==
2012-08-01 09:54:47 AUDIT nova.service [-] Starting network node (version 2012.1.1-LOCALBRANCH:LOCALREVISION)
2012-08-01 09:54:53 INFO nova.rpc.impl_qpid [-] Connected to AMQP server on localhost:5672
2012-08-01 17:09:44 AUDIT nova.service [-] Starting network node (version 2012.1.1-LOCALBRANCH:LOCALREVISION)
2012-08-01 17:10:06 INFO nova.rpc.impl_qpid [-] Connected to AMQP server on localhost:5672
2012-08-01 19:02:11 AUDIT nova.service [-] Starting network node (version 2012.1.1-LOCALBRANCH:LOCALREVISION)
2012-08-01 19:02:17 INFO nova.rpc.impl_qpid [-] Connected to AMQP server on localhost:5672
2012-08-01 23:07:52 AUDIT nova.service [-] Starting network node (version 2012.1.1-LOCALBRANCH:LOCALREVISION)
2012-08-01 23:07:58 INFO nova.rpc.impl_qpid [-] Connected to AMQP server on localhost:5672
2012-08-02 21:30:57 AUDIT nova.service [-] Starting network node (version 2012.1.1-LOCALBRANCH:LOCALREVISION)
2012-08-02 21:31:03 INFO nova.rpc.impl_qpid [-] Connected to AMQP server on localhost:5672

==> /var/log/nova/nova-manage.log <==
2012-07-31 19:40:12 WARNING nova.utils [-] /usr/lib64/python2.7/site-packages/sqlalchemy/pool.py:683: SADeprecationWarning: The 'listeners' argument to Pool (and create_engine()) is deprecated.  Use event.listen().
  Pool.__init__(self, creator, **kw)

2012-07-31 19:40:12 WARNING nova.utils [-] /usr/lib64/python2.7/site-packages/sqlalchemy/pool.py:159: SADeprecationWarning: Pool.add_listener is deprecated.  Use event.listen()
  self.add_listener(l)

2012-07-31 19:40:12 AUDIT nova.db.sqlalchemy.fix_dns_domains [-] Applying database fix for Essex dns_domains table.

==> /var/log/nova/objectstore.log <==
2012-07-31 19:47:00 INFO nova.wsgi [-] Started S3 Objectstore on 10.0.2.15:3333
2012-07-31 22:16:53 INFO nova.wsgi [-] Started S3 Objectstore on 10.0.2.15:3333
2012-08-01 09:54:47 INFO nova.wsgi [-] Started S3 Objectstore on 10.0.2.15:3333
2012-08-01 17:09:40 INFO nova.wsgi [-] Started S3 Objectstore on 10.0.2.15:3333
2012-08-01 19:02:10 INFO nova.wsgi [-] Started S3 Objectstore on 10.0.2.15:3333
2012-08-01 23:07:51 INFO nova.wsgi [-] Started S3 Objectstore on 10.0.2.15:3333
2012-08-02 21:30:56 INFO nova.wsgi [-] Started S3 Objectstore on 10.0.2.15:3333

==> /var/log/nova/scheduler.log <==
2012-08-01 17:10:06 INFO nova.rpc.impl_qpid [req-e8d8d756-7751-403c-a348-f8a0f24a63a6 None None] Connected to AMQP server on localhost:5672
2012-08-01 19:02:11 AUDIT nova.service [-] Starting scheduler node (version 2012.1.1-LOCALBRANCH:LOCALREVISION)
2012-08-01 19:02:12 WARNING nova.db.sqlalchemy.session [req-8b22e296-436c-4bd6-bdcf-1307f511f2b5 None None] SQL connection failed. 10 attempts left.
2012-08-01 19:02:23 INFO nova.rpc.impl_qpid [req-8b22e296-436c-4bd6-bdcf-1307f511f2b5 None None] Connected to AMQP server on localhost:5672
2012-08-01 23:07:52 AUDIT nova.service [-] Starting scheduler node (version 2012.1.1-LOCALBRANCH:LOCALREVISION)
2012-08-01 23:07:55 INFO nova.rpc.impl_qpid [req-21bd76ae-b802-4ed3-bfc3-a76f8903c163 None None] Connected to AMQP server on localhost:5672
2012-08-01 23:26:42 WARNING nova.scheduler.manager [req-795fba61-88d9-46a5-babc-c32c5be847b1 02720e417b5b4b7c8f00e1e2e5fc0cf0 59599870461543f9a502a163e3b6931f] Failed to schedule_run_instance: No valid host was found. 
2012-08-01 23:26:42 WARNING nova.scheduler.manager [req-795fba61-88d9-46a5-babc-c32c5be847b1 02720e417b5b4b7c8f00e1e2e5fc0cf0 59599870461543f9a502a163e3b6931f] Setting instance d08a6804-3532-4611-81b3-5d8cc8f2a321 to ERROR state.
2012-08-02 21:30:57 AUDIT nova.service [-] Starting scheduler node (version 2012.1.1-LOCALBRANCH:LOCALREVISION)
2012-08-02 21:31:00 INFO nova.rpc.impl_qpid [req-35b8af7b-4546-4f0d-b7c0-7eb1f8359d80 None None] Connected to AMQP server on localhost:5672

==> /var/log/nova/volume.log <==
2012-08-01 09:54:47 AUDIT nova.service [-] Starting volume node (version 2012.1.1-LOCALBRANCH:LOCALREVISION)
2012-08-01 09:54:49 CRITICAL nova [-] volume group nova-volumes doesn't exist
2012-08-01 17:09:41 AUDIT nova.service [-] Starting volume node (version 2012.1.1-LOCALBRANCH:LOCALREVISION)
2012-08-01 17:10:00 CRITICAL nova [-] volume group nova-volumes doesn't exist
2012-08-01 19:02:10 AUDIT nova.service [-] Starting volume node (version 2012.1.1-LOCALBRANCH:LOCALREVISION)
2012-08-01 19:02:13 CRITICAL nova [-] volume group nova-volumes doesn't exist
2012-08-01 23:07:52 AUDIT nova.service [-] Starting volume node (version 2012.1.1-LOCALBRANCH:LOCALREVISION)
2012-08-01 23:07:54 CRITICAL nova [-] volume group nova-volumes doesn't exist
2012-08-02 21:30:56 AUDIT nova.service [-] Starting volume node (version 2012.1.1-LOCALBRANCH:LOCALREVISION)
2012-08-02 21:30:59 CRITICAL nova [-] volume group nova-volumes doesn't exist
....

> also try
>>  sudo virsh list --all
> to see if the vm in defined but not started for some reason.

$ sudo virsh list --all
[sudo] password for satimis: 
 Id    Name                           State
----------------------------------------------------

Thanks

B.R.
SL