Savanna with Nova-network with Grizlly

Hello Sarita,

Please make sure that your OpenStack environment configured correctly.
To do this try to launch test instance (e.g. https://launchpad.net/cirros/) without Savanna
Perhaps Nova can't communicate with Keystone because i see message about authorization problem in the traceback. In this case you need check credentials specified in the /etc/nova/nova-api.ini

Hii Alexander Rubtsov,

OpenStack environment is configured correctly. I had checked it once again .
I had also launched a test instance successfully without Savanna. I had also gone through the credentials specified in /etc/nova/nova-api.ini.

But still i am facing the same problem i.e. Cluster remains in waiting state for some hours and then changed into Error with two launched instance :master and slave.

Sarita,

Please attach full Savanna log. In order to create it launch savanna-api with flag "--log-file <PATH>"
Also let's check state of instances. Attach the output of command "nova console-log <instance_ID>" after cluster goes to error state.

The state of instances are active but cluster state goes in error state.

The savanna log is as follows as:

127.0.0.1 - - [08/Aug/2013 20:18:30] "GET /v1.0/fd6e0af3983444bbaa41124740f373d9/clusters/1935935b-b8a2-4525-b2ed-000baf723c22 HTTP/1.1" 200 1790 0.012766
(23643) accepted ('127.0.0.1', 59464)
127.0.0.1 - - [08/Aug/2013 20:19:01] "GET /v1.0/fd6e0af3983444bbaa41124740f373d9/clusters/1935935b-b8a2-4525-b2ed-000baf723c22 HTTP/1.1" 200 1790 0.040173
(23643) accepted ('127.0.0.1', 59781)
127.0.0.1 - - [08/Aug/2013 20:19:31] "GET /v1.0/fd6e0af3983444bbaa41124740f373d9/clusters/1935935b-b8a2-4525-b2ed-000baf723c22 HTTP/1.1" 200 1790 0.034558
(23643) accepted ('127.0.0.1', 60114)
127.0.0.1 - - [08/Aug/2013 20:20:02] "GET /v1.0/fd6e0af3983444bbaa41124740f373d9/clusters/1935935b-b8a2-4525-b2ed-000baf723c22 HTTP/1.1" 200 1790 0.018801
(23643) accepted ('127.0.0.1', 60432)
127.0.0.1 - - [08/Aug/2013 20:20:32] "GET /v1.0/fd6e0af3983444bbaa41124740f373d9/clusters/1935935b-b8a2-4525-b2ed-000baf723c22 HTTP/1.1" 200 1790 0.025333
(23643) accepted ('127.0.0.1', 60756)
127.0.0.1 - - [08/Aug/2013 20:21:02] "GET /v1.0/fd6e0af3983444bbaa41124740f373d9/clusters/1935935b-b8a2-4525-b2ed-000baf723c22 HTTP/1.1" 200 1790 0.015351
(23643) accepted ('127.0.0.1', 32849)
127.0.0.1 - - [08/Aug/2013 20:21:33] "GET /v1.0/fd6e0af3983444bbaa41124740f373d9/clusters/1935935b-b8a2-4525-b2ed-000baf723c22 HTTP/1.1" 200 1790 0.018000
(23643) accepted ('127.0.0.1', 33179)
127.0.0.1 - - [08/Aug/2013 20:22:04] "GET /v1.0/fd6e0af3983444bbaa41124740f373d9/clusters/1935935b-b8a2-4525-b2ed-000baf723c22 HTTP/1.1" 200 1790 0.015437
(23643) accepted ('127.0.0.1', 33501)
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/eventlet/greenpool.py", line 80, in _spawn_n_impl
    func(*args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/eventlet/wsgi.py", line 584, in process_request
    proto.__init__(socket, address, self)
  File "/usr/lib/python2.7/SocketServer.py", line 638, in __init__
    self.handle()
  File "/usr/lib/python2.7/BaseHTTPServer.py", line 340, in handle
    self.handle_one_request()
  File "/usr/local/lib/python2.7/dist-packages/eventlet/wsgi.py", line 226, in handle_one_request
    self.raw_requestline = self.rfile.readline(self.server.url_length_limit)
  File "/usr/lib/python2.7/socket.py", line 476, in readline
    data = self._sock.recv(self._rbufsize)
  File "/usr/local/lib/python2.7/dist-packages/eventlet/greenio.py", line 262, in recv
    timeout_exc=socket.timeout("timed out"))
  File "/usr/local/lib/python2.7/dist-packages/eventlet/hubs/__init__.py", line 151, in trampoline
    listener = hub.add(hub.READ, fileno, current.switch)
  File "/usr/local/lib/python2.7/dist-packages/eventlet/hubs/epolls.py", line 48, in add
    listener = BaseHub.add(self, evtype, fileno, cb)
  File "/usr/local/lib/python2.7/dist-packages/eventlet/hubs/hub.py", line 126, in add
    evtype, fileno, evtype))
RuntimeError: Second simultaneous read on fileno 23 detected. Unless you really know what you're doing, make sure that only one greenthread can read any particular socket. Consider using a pools.Pool. If you do know what you're doing and want to disable this error, call eventlet.debug.hub_prevent_multiple_readers(False)
2013-08-09 09:51:23.123 23643 WARNING savanna.service.instances [-] Can't start cluster 'aai-hadoop' (reason: Unauthorized (HTTP 401))
2013-08-09 09:51:23.548 23643 ERROR root [-] Original exception being dropped: ['Traceback (most recent call last):\n', ' File "/usr/local/lib/python2.7/dist-packages/savanna/service/instances.py", line 39, in create_cluster\n _await_instances(cluster)\n', ' File "/usr/local/lib/python2.7/dist-packages/savanna/service/instances.py", line 208, in _await_instances\n if not _check_if_up(instance):\n', ' File "/usr/local/lib/python2.7/dist-packages/savanna/service/instances.py", line 217, in _check_if_up\n server = nova.get_instance_info(instance)\n', ' File "/usr/local/lib/python2.7/dist-packages/savanna/utils/openstack/nova.py", line 69, in get_instance_info\n return client().servers.get(instance.instance_id)\n', ' File "/usr/local/lib/python2.7/dist-packages/novaclient/v1_1/servers.py", line 365, in get\n return self._get("/servers/%s" % base.getid(server), "server")\n', ' File "/usr/local/lib/python2.7/dist-packages/novaclient/base.py", line 139, in _get\n _resp, body = self.api.client.get(url)\n', ' File "/usr/local/lib/python2.7/dist-packages/novaclient/client.py", line 229, in get\n return self._cs_request(url, \'GET\', **kwargs)\n', ' File "/usr/local/lib/python2.7/dist-packages/novaclient/client.py", line 226, in _cs_request\n raise e\n', 'Unauthorized: Unauthorized (HTTP 401)\n']
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/eventlet/hubs/poll.py", line 97, in wait
    readers.get(fileno, noop).cb(fileno)
  File "/usr/local/lib/python2.7/dist-packages/eventlet/greenthread.py", line 194, in main
    result = function(*args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/savanna/context.py", line 132, in wrapper
    func(*args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/savanna/service/api.py", line 111, in _provision_cluster
    i.create_cluster(cluster)
  File "/usr/local/lib/python2.7/dist-packages/savanna/service/instances.py", line 52, in create_cluster
    _rollback_cluster_creation(cluster, ex)
  File "/usr/local/lib/python2.7/dist-packages/savanna/service/instances.py", line 277, in _rollback_cluster_creation
    _shutdown_instances(cluster, True)
  File "/usr/local/lib/python2.7/dist-packages/savanna/service/instances.py", line 306, in _shutdown_instances
    _shutdown_instance(instance)
  File "/usr/local/lib/python2.7/dist-packages/savanna/service/instances.py", line 312, in _shutdown_instance
    nova.client().servers.delete(instance.instance_id)
  File "/usr/local/lib/python2.7/dist-packages/novaclient/v1_1/servers.py", line 668, in delete
    self._delete("/servers/%s" % base.getid(server))
  File "/usr/local/lib/python2.7/dist-packages/novaclient/base.py", line 153, in _delete
    _resp, _body = self.api.client.delete(url)
  File "/usr/local/lib/python2.7/dist-packages/novaclient/client.py", line 238, in delete
    return self._cs_request(url, 'DELETE', **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/novaclient/client.py", line 226, in _cs_request
    raise e
Unauthorized: Unauthorized (HTTP 401)
Removing descriptor: 16
(23643) accepted ('127.0.0.1', 39164)
127.0.0.1 - - [12/Aug/2013 09:48:35] "GET /v1.0/fd6e0af3983444bbaa41124740f373d9/clusters HTTP/1.1" 200 1962 0.284868

Sarita,

Did you install Savanna in a separate python virtual environment?
In order to do that run: "cd ~; virtualenv savanna-venv"
This will install new virtual environment into savanna-venv directory in your home directory.

Then you can install Savanna inside this virtual environment:
"savanna-venv/bin/pip install savanna"
(for more information please visit http://savanna.readthedocs.org/en/latest/userdoc/installation.guide.html)

After that try to create cluster again

Also, the "ACTIVE" state sets before the instance is completely launched. Therefore need the output of "nova console-log <instance_ID>" after cluster goes to error state

Alexander Rubtsov ,

Yes, I had installed Savanna in a separate python virtual environment using the same reference :http://savanna.readthedocs.org/en/latest/userdoc/installation.guide.html

Cluster State remains in Waiting state after launching the instance and after 1 day it will go into error state. So I will be unable to give you the output of "nova console-log <instance_ID>" tomorrow when cluster goes to error state.

Alexander Rubtsov ,

The Cluster state switches directly from Spawning to Waiting.

I can update you about the launched active state instance console-log,if you want.

Sorry but I'll be only able to give you the output of "nova console-log <instance_ID>" tomorrow when cluster goes to error state.

I suppose that the creation of a cluster ends with error "Unauthorized" and exactly after 1 day, due to the fact that the token provided by Keystone expires (validity of the token by default exactly 24 hours).

To test that next time you can before attempting to create a cluster temporarily decrease parameter value "expiration" in the /etc/keystone/keystone.conf

If this assumption is correct, then you will not forced to wait so long every time

I had decrease the value of expiration from 86400 to 864 in the /etc/keystone/keystone.conf.
Then database synchronization and start all the nova services and apache2 server.

This all did not helped me out. My cluster is still in waiting state from last 4 hour.
My nova console-log for active instance (after cluster goes into error state) is as follows as:

Instance1:
<------------------------------------------------------------------------->
..............................................................................
[ 0.407413] pnp: PnP ACPI: found 8 devices
[ 0.408832] ACPI: ACPI bus type pnp unregistered
[ 0.446954] NET: Registered protocol family 2
[ 0.448505] IP route cache hash table entries: 4096 (order: 3, 32768 bytes)
[ 0.450843] TCP established hash table entries: 16384 (order: 6, 262144 bytes)
[ 0.453757] TCP bind hash table entries: 16384 (order: 6, 262144 bytes)
[ 0.456131] TCP: Hash tables configured (established 16384 bind 16384)
[ 0.459077] TCP: reno registered
[ 0.460269] UDP hash table entries: 256 (order: 1, 8192 bytes)
[ 0.462055] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)
[ 0.464050] NET: Registered protocol family 1
[ 0.465487] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[ 0.467332] pci 0000:00:01.0: PIIX3: Enabling Passive Release
[ 0.469206] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[ 0.471212] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11
[ 0.473788] audit: initializing netlink socket (disabled)
[ 0.475512] type=2000 audit(1376301101.472:1): initialized
[ 0.477389] Trying to unpack rootfs image as initramfs...
[ 0.529422] HugeTLB registered 2 MB page size, pre-allocated 0 pages
[ 0.533234] VFS: Disk quotas dquot_6.5.2
[ 0.534622] Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[ 0.544243] fuse init (API version 7.19)
[ 0.545667] msgmni has been set to 939
[ 0.560223] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[ 0.562686] io scheduler noop registered
[ 0.563987] io scheduler deadline registered (default)
[ 0.572293] io scheduler cfq registered
[ 0.573729] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
[ 0.575454] pciehp: PCI Express Hot Plug Controller Driver version: 0.4
[ 0.577614] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[ 0.580044] ACPI: Power Button [PWRF]
[ 0.583208] GHES: HEST is not enabled!
[ 0.592651] ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 10
[ 0.600195] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled
[ 0.624673] serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[ 0.674575] serial8250: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
[ 0.734591] 00:05: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[ 0.779096] 00:06: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
[ 0.804373] Linux agpgart interface v0.103
[ 0.813653] brd: module loaded
[ 0.815867] loop: module loaded
[ 0.884614] vda: vda1
[ 0.912109] scsi0 : ata_piix
[ 0.913322] scsi1 : ata_piix
[ 0.914465] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc180 irq 14
[ 0.916462] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc188 irq 15
[ 0.919445] Fixed MDIO Bus: probed
[ 0.920713] tun: Universal TUN/TAP device driver, 1.6
[ 0.922345] tun: (C) 1999-2004 Max Krasnyansky <email address hidden>
[ 0.928295] PPP generic driver version 2.4.2
[ 0.936063] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 0.938096] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[ 0.939935] uhci_hcd: USB Universal Host Controller Interface driver
[ 0.948243] uhci_hcd 0000:00:01.2: UHCI Host Controller
[ 0.949875] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
[ 0.952506] uhci_hcd 0000:00:01.2: irq 11, io base 0x0000c140
[ 0.954365] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001
[ 0.956464] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.958940] usb usb1: Product: UHCI Host Controller
[ 0.960587] usb usb1: Manufacturer: Linux 3.5.0-31-generic uhci_hcd
[ 0.962552] usb usb1: SerialNumber: 0000:00:01.2
[ 0.976323] hub 1-0:1.0: USB hub found
[ 0.977725] hub 1-0:1.0: 2 ports detected
[ 0.979290] usbcore: registered new interface driver libusual
[ 0.988104] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[ 0.991840] serio: i8042 KBD port at 0x60,0x64 irq 1
[ 1.000114] serio: i8042 AUX port at 0x60,0x64 irq 12
[ 1.001988] mousedev: PS/2 mouse device common for all mice
[ 1.004261] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1
[ 1.007236] rtc_cmos 00:01: RTC can wake from S4
[ 1.009431] rtc_cmos 00:01: rtc core: registered rtc_cmos as rtc0
[ 1.011520] rtc0: alarms up to one day, 114 bytes nvram, hpet irqs
[ 1.020235] device-mapper: uevent: version 1.0.3
[ 1.021968] device-mapper: ioctl: 4.22.0-ioctl (2011-10-19) initialised: <email address hidden>
[ 1.024862] cpuidle: using governor ladder
[ 1.026275] cpuidle: using governor menu
[ 1.027784] EFI Variables Facility v0.08 2004-May-17
[ 1.040144] ashmem: initialized
[ 1.041575] TCP: cubic registered
[ 1.043005] NET: Registered protocol family 10
[ 1.048564] NET: Registered protocol family 17
[ 1.050130] Key type dns_resolver registered
[ 1.056166] registered taskstats version 1
[ 1.285058] Freeing initrd memory: 18524k freed
[ 1.310450] usb 1-1: new full-speed USB device number 2 using uhci_hcd
[ 1.320759] Key type trusted registered
[ 1.330199] Key type encrypted registered
[ 1.339076] Magic number: 9:206:879
[ 1.340740] rtc_cmos 00:01: setting system clock to 2013-08-12 09:51:41 UTC (1376301101)
[ 1.343493] BIOS EDD facility v0.16 2004-Jun-25, 0 devices found
[ 1.345448] EDD information not available.
[ 1.348853] Freeing unused kernel memory: 932k freed
[ 1.350895] Write protecting the kernel read-only data: 12288k
[ 1.357383] Freeing unused kernel memory: 1472k freed
[ 1.363047] Freeing unused kernel memory: 1132k freed
Loading, please wait...
[ 1.473090] Refined TSC clocksource calibration: 2394.002 MHz.
[ 1.598812] udevd[87]: starting version 175
[ 1.703454] usb 1-1: New USB device found, idVendor=0627, idProduct=0001
[ 1.705650] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=5
[ 1.708556] usb 1-1: Product: QEMU USB Tablet
[ 1.710057] usb 1-1: Manufacturer: QEMU 1.0
[ 1.711524] usb 1-1: SerialNumber: 42
[ 2.136680] 8139cp: 8139cp: 10/100 PCI Ethernet driver v1.3 (Mar 22, 2004)
[ 2.139182] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11
[ 2.176581] 8139cp 0000:00:03.0: eth0: RTL-8139C+ at 0xffffc9000015a000, fa:16:3e:67:9e:a7, IRQ 11
[ 2.200573] 8139too: 8139too Fast Ethernet driver 0.9.28
[ 2.444679] FDC 0 is a S82078B
[ 2.464912] usbcore: registered new interface driver usbhid
[ 2.466885] usbhid: USB HID core driver
[ 2.482416] input: QEMU 1.0 QEMU USB Tablet as /devices/pci0000:00/0000:00:01.2/usb1/1-1/1-1:1.0/input/input2
[ 2.492436] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v0.01 Pointer [QEMU 1.0 QEMU USB Tablet] on usb-0000:00:01.2-1/input0
FATAL: Error inserting vesafb (/lib/modules/3.5.0-31-generic/kernel/drivers/video/vesafb.ko): No such device
error: unexpectedly disconnected from boot status daemon
Begin: Loading essential drivers ... done.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ... done.
Begin: Running /scripts/local-premount ... done.
[ 3.446795] EXT4-fs (vda1): mounted filesystem with ordered data mode. Opts: (null)
Begin: Running /scripts/local-bottom ... done.
done.
Begin: Running /scripts/init-bottom ... done.
[ 5.602105] EXT4-fs (vda1): re-mounted. Opts: (null)
mountall: Disconnected from Plymouth
Cloud-init v. 0.7 running 'init-local' at Mon, 12 Aug 2013 09:51:57 +0000. Up 17.29 seconds.
Cloud-init v. 0.7 running 'init' at Mon, 12 Aug 2013 09:51:59 +0000. Up 19.56 seconds.
ci-info: ++++++++++++++++++++++++++Net device info++++++++++++++++++++++++++
ci-info: +--------+------+-----------+-----------------+-------------------+
ci-info: | Device | Up | Address | Mask | Hw-Address |
ci-info: +--------+------+-----------+-----------------+-------------------+
ci-info: | lo | True | 127.0.0.1 | 255.0.0.0 | . |
ci-info: | eth0 | True | 10.1.1.4 | 255.255.255.224 | fa:16:3e:67:9e:a7 |
ci-info: +--------+------+-----------+-----------------+-------------------+
ci-info: +++++++++++++++++++++++++++++++Route info+++++++++++++++++++++++++++++++
ci-info: +-------+-------------+----------+-----------------+-----------+-------+
ci-info: | Route | Destination | Gateway | Genmask | Interface | Flags |
ci-info: +-------+-------------+----------+-----------------+-----------+-------+
ci-info: | 0 | 0.0.0.0 | 10.1.1.3 | 0.0.0.0 | eth0 | UG |
ci-info: | 1 | 10.1.1.0 | 0.0.0.0 | 255.255.255.224 | eth0 | U |
ci-info: +-------+-------------+----------+-----------------+-----------+-------+
Generating public/private rsa key pair.
Your identification has been saved in /etc/ssh/ssh_host_rsa_key.
Your public key has been saved in /etc/ssh/ssh_host_rsa_key.pub.
The key fingerprint is:
d2:10:65:ff:b3:7b:c0:d7:38:cf:db:e6:c8:94:60:61 root@h-cluster-hadoop-master-001
The key's randomart image is:
+--[ RSA 2048]----+
| ..o |
| o . |
| . . E |
| o o . |
| . S .= o |
| . .o++..|
| .oo+ |
| +..=|
| ..o++|
+-----------------+
Generating public/private dsa key pair.
Your identification has been saved in /etc/ssh/ssh_host_dsa_key.
Your public key has been saved in /etc/ssh/ssh_host_dsa_key.pub.
The key fingerprint is:
3f:4b:7a:6c:b2:6f:9f:d2:77:4e:0c:13:8b:3f:51:84 root@h-cluster-hadoop-master-001
The key's randomart image is:
+--[ DSA 1024]----+
| ..|
| E. |
| . .|
| . + |
| S . = |
| . . = |
| .+. o o|
| .o*o...o.|
| oBooo. o.|
+-----------------+
Generating public/private ecdsa key pair.
Your identification has been saved in /etc/ssh/ssh_host_ecdsa_key.
Your public key has been saved in /etc/ssh/ssh_host_ecdsa_key.pub.
The key fingerprint is:
0b:a9:25:4f:16:d2:56:9e:8d:6f:92:1d:74:d0:5b:49 root@h-cluster-hadoop-master-001
The key's randomart image is:
+--[ECDSA 256]---+
| . oo..E. |
| . o = .. o |
| . + + o o |
| o o + .. |
| . * S + |
| B . + |
| . . . |
| |
| |
+-----------------+
 * Starting AppArmor profiles [80G Cloud-init v. 0.7 running 'modules:config' at Mon, 12 Aug 2013 09:52:08 +0000. Up 28.09 seconds.
Skipping profile in /etc/apparmor.d/disable: usr.sbin.rsyslogd
[74G[ OK ]
[74G[ OK ]g iSCSI initiator service iscsid [80G
 * Setting up iSCSI targets [80G
iscsiadm: No records found
[74G[ OK ]
[74G[ OK ]g network filesystems [80G
landscape-client is not configured, please run landscape-config.
+ dib-first-boot
+ touch /var/log/first-boot.d.log
+ chmod 0600 /var/log/first-boot.d.log
+ run-parts /etc/first-boot.d
Generating locales...
  en_US.UTF-8... up-to-date
Generation complete.
Cloud-init v. 0.7 running 'modules:final' at Mon, 12 Aug 2013 09:52:18 +0000. Up 38.04 seconds.
/var/lib/cloud/instance/scripts/part-001: line 2: /home/test//.ssh/authorized_keys: No such file or directory
/var/lib/cloud/instance/scripts/part-001: line 29: /home/test//.ssh/id_rsa: No such file or directory
2013-08-12 09:52:18,479 - util.py[WARNING]: Failed running /var/lib/cloud/instance/scripts/part-001 [1]
2013-08-12 09:52:18,526 - cc_scripts_user.py[WARNING]: Failed to run module scripts-user (scripts in /var/lib/cloud/instance/scripts)
2013-08-12 09:52:18,528 - util.py[WARNING]: Running scripts-user (<module 'cloudinit.config.cc_scripts_user' from '/usr/lib/python2.7/dist-packages/cloudinit/config/cc_scripts_user.pyc'>) failed
2013-08-12 09:52:18,615 - util.py[WARNING]: Running ssh-authkey-fingerprints (<module 'cloudinit.config.cc_ssh_authkey_fingerprints' from '/usr/lib/python2.7/dist-packages/cloudinit/config/cc_ssh_authkey_fingerprints.pyc'>) failed
ec2:
ec2: #############################################################
ec2: -----BEGIN SSH HOST KEY FINGERPRINTS-----
ec2: 1024 3f:4b:7a:6c:b2:6f:9f:d2:77:4e:0c:13:8b:3f:51:84 root@h-cluster-hadoop-master-001 (DSA)
ec2: 256 0b:a9:25:4f:16:d2:56:9e:8d:6f:92:1d:74:d0:5b:49 root@h-cluster-hadoop-master-001 (ECDSA)
ec2: 2048 d2:10:65:ff:b3:7b:c0:d7:38:cf:db:e6:c8:94:60:61 root@h-cluster-hadoop-master-001 (RSA)
ec2: -----END SSH HOST KEY FINGERPRINTS-----
ec2: #############################################################
-----BEGIN SSH HOST KEY KEYS-----
ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBKsAux6imBWJSZrmbZkax72BHEdFWUxdghRHmChc2afgbhOvcwH/MtqdZb++Y95G8RUFuqSRnJ5PYBhbwQ5FYVM= root@h-cluster-hadoop-master-001
ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCs4KsrodgccuMMJYUmW6fc/GKuMKn7yGf4lnq6Pn5ZVaMMzQ+3sLC8zRPqvnlsvBcz5s412ODSSqDQYhF8/+thTmmi6G+5aNLtY1jnAKjVfj/dyii4RY60cUQ4owxWhYGERFbBeT58G5NgA82f+oGbANosFzf2RF+13pq+fP/at4LdZYMxYEV88voV7c2m7PJy5DwiwnT+krreYe3yyCxauQaQ1JCsp9bOlBbB821priDRKtAgT+HwfU9eyaM6hJtTmpC4u8XkLh2PvAFIA2OOFF3obS/KgHvQPOJZQun1V4HSWuDMM5YG7IbPAjwYjymh4BukDxsNtKLq9YSaxpR7 root@h-cluster-hadoop-master-001
-----END SSH HOST KEY KEYS-----
Cloud-init v. 0.7 finished at Mon, 12 Aug 2013 09:52:18 +0000. Datasource DataSourceEc2. Up 38.58 seconds

Sarita,

At first, please describe what image do you use. Did you build it or download (if you downloaded it - please give link)?
Can you connect via ssh from the host on which the Savanna installed to an instance by fixed ip address (for example for instance, that you showed is 10.1.1.4)?
Also attach Savanna log in the DEBUG mode. In order to create it launch savanna-api with flags "--log-file <PATH> -d"

To apply the settings expiration time, service keystone should be restarted.

I am using an image downloaded from http://savanna-files.mirantis.com/savanna-0.1.2-hadoop.qcow2.

Yes, I am able to connect via ssh from the host on which the Savanna installed to an instance by fixed ip address. But its asking for password and i do not know the password for root. Ping to this IP is giving response.

I had restarted keystone service too after applying the settings expiration time but still my cluster is in waiting state.Now I had switched from grizzly to Folsom with nova-network but facing the same problem i.e. "Cluster in waiting state".

I do not know from where I can attach a document that's why pasting here the Savanna Log :

[....................................
2013-08-13 17:29:17.852 3487 INFO requests.packages.urllib3.connectionpool [-] Starting new HTTP connection (1): 10.208.36.50
2013-08-13 17:29:17.902 3487 DEBUG requests.packages.urllib3.connectionpool [-] "GET /v2/fd6e0af3983444bbaa41124740f373d9/os-networks HTTP/1.1" 200 655 _make_request /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:296
2013-08-13 17:29:18.824 3487 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/local/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:448
2013-08-13 17:29:18.824 3487 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/local/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:506
2013-08-13 17:29:18.825 3487 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token f624dfb4302b456181ea0d6cbe29a013 _cache_get /usr/local/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:893
2013-08-13 17:29:18.826 3487 DEBUG savanna.utils.api [-] Rest.route.decorator.handler, kwargs={'tenant_id': u'fd6e0af3983444bbaa41124740f373d9', 'cluster_id': u'e57a136f-5dbd-4248-be31-bcea7bdd692e'} handler /usr/local/lib/python2.7/dist-packages/savanna/utils/api.py:60
2013-08-13 17:29:18.905 3487 INFO requests.packages.urllib3.connectionpool [-] Starting new HTTP connection (1): 10.208.36.50
2013-08-13 17:29:18.999 3487 DEBUG requests.packages.urllib3.connectionpool [-] "GET /v2/fd6e0af3983444bbaa41124740f373d9/servers/7842bd41-259e-4d30-9458-9d752fa56b71 HTTP/1.1" 200 1477 _make_request /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:296
2013-08-13 17:29:19.001 3487 INFO requests.packages.urllib3.connectionpool [-] Starting new HTTP connection (1): 10.208.36.50
2013-08-13 17:29:19.052 3487 DEBUG requests.packages.urllib3.connectionpool [-] "GET /v2/fd6e0af3983444bbaa41124740f373d9/os-networks HTTP/1.1" 200 655 _make_request /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:296

........................................]

What version of Savanna do you use? Your image intended to old version (0.1)

There is a image for the Savanna 0.2.x:
http://savanna-files.mirantis.com/savanna-0.2-vanilla-1.1.2-ubuntu-12.10.qcow2 (Notice that at registration of this image you should specify username=ubuntu)

Alexander Rubtsov,,,

Thanks for your kind concern.

I had used this image now and register it with username=ubuntu but my cluster is still in waiting state.

When I am starting the savanna call my savanna log for the command " savanna-venv/bin/python savanna-venv/bin/savanna-api --log-file /var/log/savanna.log -d" is:

2013-08-14 11:08:45.204 6149 DEBUG savanna.openstack.common.lockutils [-] Got semaphore "dbapi_backend" lock /etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/openstack/common/lockutils.py:166
2013-08-14 11:08:45.204 6149 DEBUG savanna.openstack.common.lockutils [-] Got semaphore / lock "__get_backend" inner /etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/openstack/common/lockutils.py:245
2013-08-14 11:08:47.058 6149 DEBUG savanna.plugins.base [-] List of requested plugins: [] _load_all_plugins /etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/plugins/base.py:113
2013-08-14 11:08:47.064 6149 DEBUG savanna.main [-] Logging of request/response exchange could be enabled using flag --log-exchange make_app /etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/main.py:125
2013-08-14 11:08:47.065 6149 INFO keystoneclient.middleware.auth_token [-] Starting keystone auth_token middleware
2013-08-14 11:08:47.066 6149 INFO keystoneclient.middleware.auth_token [-] Using /tmp/keystone-signing-q7t18x as cache directory for signing certificate
2013-08-14 11:08:47.067 6149 CRITICAL savanna [-] [Errno 98] Address already in use

and when not starting the savanna using command "savanna-venv/bin/python savanna-venv/bin/savanna-api --config-file savanna-venv/etc/savanna.conf" is:

2013-08-14 11:04:32.609 5550 DEBUG savanna.openstack.common.lockutils [-] Got semaphore "dbapi_backend" lock /etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/openstack/common/lockutils.py:166
2013-08-14 11:04:32.609 5550 DEBUG savanna.openstack.common.lockutils [-] Got semaphore / lock "__get_backend" inner /etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/openstack/common/lockutils.py:245
2013-08-14 11:04:34.753 5550 DEBUG savanna.plugins.base [-] List of requested plugins: [] _load_all_plugins /etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/plugins/base.py:113
2013-08-14 11:04:34.760 5550 DEBUG savanna.main [-] Logging of request/response exchange could be enabled using flag --log-exchange make_app /etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/main.py:125
2013-08-14 11:04:34.760 5550 INFO keystoneclient.middleware.auth_token [-] Starting keystone auth_token middleware
2013-08-14 11:04:34.761 5550 INFO keystoneclient.middleware.auth_token [-] Using /tmp/keystone-signing-2xoig5 as cache directory for signing certificate
(5550) wsgi starting up on http://0.0.0.0:8386/
(5550) accepted ('10.208.36.50', 33079)
2013-08-14 11:04:50.403 5550 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /etc/init.d/savanna-venv/local/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:448
2013-08-14 11:04:50.403 5550 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /etc/init.d/savanna-venv/local/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:506
2013-08-14 11:04:50.441 5550 DEBUG keystoneclient.middleware.auth_token [-] Server reports support for api versions: v2.0 _get_supported_versions /etc/init.d/savanna-venv/local/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:438
2013-08-14 11:04:50.441 5550 INFO keystoneclient.middleware.auth_token [-] Auth Token confirmed use of v2.0 apis
2013-08-14 11:04:50.564 5550 WARNING keystoneclient.middleware.auth_token [-] Unexpected response from keystone service: {u'error': {u'message': u'Invalid user / password', u'code': 401, u'title': u'Not Authorized'}}
2013-08-14 11:04:50.564 5550 DEBUG keystoneclient.middleware.auth_token [-] Token validation failure. _validate_user_token /etc/init.d/savanna-venv/local/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:707
2013-08-14 11:04:50.564 5550 TRACE keystoneclient.middleware.auth_token Traceback (most recent call last):
2013-08-14 11:04:50.564 5550 TRACE keystoneclient.middleware.auth_token File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py", line 702, in _validate_user_token
2013-08-14 11:04:50.564 5550 TRACE keystoneclient.middleware.auth_token data = self.verify_uuid_token(user_token, retry)
2013-08-14 11:04:50.564 5550 TRACE keystoneclient.middleware.auth_token File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py", line 990, in verify_uuid_token
2013-08-14 11:04:50.564 5550 TRACE keystoneclient.middleware.auth_token headers = {'X-Auth-Token': self.get_admin_token()}
2013-08-14 11:04:50.564 5550 TRACE keystoneclient.middleware.auth_token File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py", line 557, in get_admin_token
2013-08-14 11:04:50.564 5550 TRACE keystoneclient.middleware.auth_token self.admin_token_expiry) = self._request_admin_token()
2013-08-14 11:04:50.564 5550 TRACE keystoneclient.middleware.auth_token File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py", line 677, in _request_admin_token
2013-08-14 11:04:50.564 5550 TRACE keystoneclient.middleware.auth_token raise ServiceError('invalid json response')
2013-08-14 11:04:50.564 5550 TRACE keystoneclient.middleware.auth_token ServiceError: invalid json response
2013-08-14 11:04:50.564 5550 TRACE keystoneclient.middleware.auth_token
2013-08-14 11:04:50.581 5550 DEBUG keystoneclient.middleware.auth_token [-] Marking token b9f2441101154530b03e4e6fe6a02d86 as unauthorized in memcache _cache_store_invalid /etc/init.d/savanna-venv/local/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:960
2013-08-14 11:04:50.581 5550 WARNING keystoneclient.middleware.auth_token [-] Authorization failed for token b9f2441101154530b03e4e6fe6a02d86
2013-08-14 11:04:50.581 5550 INFO keystoneclient.middleware.auth_token [-] Invalid user token - rejecting request
10.208.36.50 - - [14/Aug/2013 11:04:50] "GET /v1.0/11f94438f0f1466d814f2cf5a6f2839a/clusters HTTP/1.1" 401 565 0.178953
(5550) accepted ('10.208.36.50', 33083)
2013-08-14 11:06:55.057 5550 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /etc/init.d/savanna-venv/local/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:448
2013-08-14 11:06:55.057 5550 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /etc/init.d/savanna-venv/local/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:506
2013-08-14 11:06:55.057 5550 DEBUG keystoneclient.middleware.auth_token [-] Cached Token b9f2441101154530b03e4e6fe6a02d86 is marked unauthorized _cache_get /etc/init.d/savanna-venv/local/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:888
2013-08-14 11:06:55.057 5550 DEBUG keystoneclient.middleware.auth_token [-] Token validation failure. _validate_user_token /etc/init.d/savanna-venv/local/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:707
2013-08-14 11:06:55.057 5550 TRACE keystoneclient.middleware.auth_token Traceback (most recent call last):
2013-08-14 11:06:55.057 5550 TRACE keystoneclient.middleware.auth_token File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py", line 695, in _validate_user_token
2013-08-14 11:06:55.057 5550 TRACE keystoneclient.middleware.auth_token cached = self._cache_get(token_id)
2013-08-14 11:06:55.057 5550 TRACE keystoneclient.middleware.auth_token File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py", line 889, in _cache_get
2013-08-14 11:06:55.057 5550 TRACE keystoneclient.middleware.auth_token raise InvalidUserToken('Token authorization failed')
2013-08-14 11:06:55.057 5550 TRACE keystoneclient.middleware.auth_token InvalidUserToken: Token authorization failed
2013-08-14 11:06:55.057 5550 TRACE keystoneclient.middleware.auth_token
2013-08-14 11:06:55.058 5550 DEBUG keystoneclient.middleware.auth_token [-] Marking token b9f2441101154530b03e4e6fe6a02d86 as unauthorized in memcache _cache_store_invalid /etc/init.d/savanna-venv/local/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:960
2013-08-14 11:06:55.058 5550 WARNING keystoneclient.middleware.auth_token [-] Authorization failed for token b9f2441101154530b03e4e6fe6a02d86
2013-08-14 11:06:55.058 5550 INFO keystoneclient.middleware.auth_token [-] Invalid user token - rejecting request
10.208.36.50 - - [14/Aug/2013 11:06:55] "GET /v1.0/11f94438f0f1466d814f2cf5a6f2839a/clusters HTTP/1.1" 401 565 0.001949

My savanna.conf is :
port=8386

log_file = savanna-api.log
# Address and credentials that will be used to check auth tokens
os_auth_host=10.208.36.50
os_auth_port=35357
os_admin_username=admin
os_admin_password=admin_pass
os_admin_tenant_name=admin

# When set to false, Savanna uses only internal IP of VMs.
# When set to true, Savanna expects OpenStack to auto-
# assign floating IPs to cluster nodes. Internal IPs will
# be used for inter-cluster communication, while floating
# ones will be used by Savanna to configure nodes. Also
# floating IPs will be exposed in service URLs.
use_floating_ips=True

# The suffix of the node's FQDN. In nova-network that is
# dhcp_domain config parameter (string value)
node_domain=novalocal

# List of plugins to be loaded. Savanna preserves the order of
# the list when returning it. (list value)
plugins=vanilla,hdp

[plugin:vanilla]
plugin_class=savanna.plugins.vanilla.plugin:VanillaProvider

[plugin:hdp]
plugin_class=savanna.plugins.hdp.ambariplugin:AmbariPlugin

[database]

# URL for sqlalchemy database (string value)
connection=sqlite:////tmp/savanna-server.db

and i had followed step by step these links :

1)https://savanna.readthedocs.org/en/latest/devref/quickstart.html
2)https://savanna.readthedocs.org/en/latest/devref/quickstart.html

and also integrated dashboard and follow this link

1) http://savanna.readthedocs.org/en/latest/horizon/installation.guide.html#prerequisites

But still my cluster is in waiting state :(

Sarita,

How do you create a new cluster: through UI or REST requests (e.g. httpie from documentation)?
If you use REST try to refresh your token (<your-savanna-venv>/bin/keystone token-get) and put it to new request (X-Auth-Token:)

I had created the cluster from both :through UI or REST requests.

I had also refreshed the token but nothing get beneficial.

In REST it also showing me the waiting state.

Now when i am going to create a new cluster using REST its giving me error :

http http://0.0.0.0:8386/v1.0/11f94438f0f1466d814f2cf5a6f2839a/clusters X-Auth-Token:dcb533e8342c44389cdd91569ff2663b < cluster_create.json

HTTP/1.1 500 INTERNAL SERVER ERROR
Content-Length: 81
Content-Type: application/json
Date: Wed, 14 Aug 2013 11:19:05 GMT

{
    "error": 500,
    "error_message": "Malformed message body: cannot understand JSON"
}

my cluster_create.json is :

{
    "name": "cluster-1",
    "plugin_name": "vanilla",
    "hadoop_version": "1.1.2",
    "cluster_template_id": "a9dc1023-ddb9-476d-a3f5-a6e9c643e614"
    "user_keypair_id": "stack",
    "default_image_id": "8afb092a-f69e-4d26-aea5-09451ac11d8d"
}

One more doubt :
In the savanna2 doumentation there is no endpoint for Hadoop.
In Earlier implementation i had created service and endpoint for hadoop but it does not work.

Is it necessary? I should declare this service and endpoint or not?

Savanna 0.2.x doesn't need endpoint creation.
Also I notice that you missed a comma at the end of the line: "cluster_template_id": "a9dc1023-ddb9-476d-a3f5-a6e9c643e614"
fix it and try to create cluster again

Ok,Thanks for correcting me.Now i am able to create cluster again using REST.

But still my cluster is in waiting state. :(

Is state "Waiting" has a cluster that you created now through REST?
Do I understand correctly that after the you have created this cluster - launched several instances in addition to those that have already been created?
In order to see whether there have been any changes after token's update please show their nova console-log (don't need wait for the transition to the ERROR state - if the instances has launched, it will be the last line: "Cloud-init v. 0.7 finished ...")

Also, I'd still like to see the debug log file (for example it can be put on http://paste.openstack.org/, beforehand hiding all private information if necessary)

Yes,the cluster created through REST was in waiting state.

I had created successfully one instance before the cluster launch.
When I created my new cluster using REST having 1 master and 1 worker node ,, The master node and worker node launched successfully as instances with internal IP and cluster went into waiting state. I again launched an instance successfully.

Thus I have 4 successfully launched instances in active state.

1)before cluster
2 & 3) Cluster---> master node and slave node
4)after cluster goes into waiting state.

I created instances before and after cluster just to check whether my nova is contacting to keystone or not .

nova console-log of cluster-- master node is as follows as --->

////////////////////////////////////////////////////////////////////////////////
[......

[ 0.526863] vgaarb: device added: PCI:0000:00:02.0,decodes=io+mem,owns=io+mem,locks=none
[ 0.528036] vgaarb: loaded
[ 0.529064] vgaarb: bridge control possible 0000:00:02.0
[ 0.532400] SCSI subsystem initialized
[ 0.534088] ACPI: bus type usb registered
[ 0.535480] usbcore: registered new interface driver usbfs
[ 0.536051] usbcore: registered new interface driver hub
[ 0.537928] usbcore: registered new device driver usb
[ 0.540386] PCI: Using ACPI for IRQ routing
[ 0.542470] NetLabel: Initializing
[ 0.544043] NetLabel: domain hash size = 128
[ 0.545438] NetLabel: protocols = UNLABELED CIPSOv4
[ 0.547009] NetLabel: unlabeled traffic allowed by default
[ 0.548201] HPET: 3 timers in total, 0 timers will be used for per-cpu timer
[ 0.550288] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
[ 0.553013] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
[ 0.560122] Switching to clocksource kvm-clock
[ 0.579695] AppArmor: AppArmor Filesystem Enabled
[ 0.970489] pnp: PnP ACPI init
[ 0.971648] ACPI: bus type pnp registered
[ 0.974063] pnp: PnP ACPI: found 8 devices
[ 0.975446] ACPI: ACPI bus type pnp unregistered
[ 0.983793] NET: Registered protocol family 2
[ 0.985417] IP route cache hash table entries: 65536 (order: 7, 524288 bytes)
[ 0.989392] TCP established hash table entries: 262144 (order: 10, 4194304 bytes)
[ 0.998635] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes)
[ 1.003642] TCP: Hash tables configured (established 262144 bind 65536)
[ 1.005719] TCP: reno registered
[ 1.006884] UDP hash table entries: 1024 (order: 3, 32768 bytes)
[ 1.008784] UDP-Lite hash table entries: 1024 (order: 3, 32768 bytes)
[ 1.010837] NET: Registered protocol family 1
[ 1.012308] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[ 1.014125] pci 0000:00:01.0: PIIX3: Enabling Passive Release
[ 1.015896] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[ 1.017977] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11
[ 1.033502] audit: initializing netlink socket (disabled)
[ 1.035208] type=2000 audit(1376481113.032:1): initialized
[ 1.037043] Trying to unpack rootfs image as initramfs...
[ 1.320896] HugeTLB registered 2 MB page size, pre-allocated 0 pages
[ 1.328782] VFS: Disk quotas dquot_6.5.2
[ 1.330348] Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[ 1.338159] fuse init (API version 7.19)
[ 1.339641] msgmni has been set to 3963
[ 1.361148] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[ 1.368343] io scheduler noop registered
[ 1.369800] io scheduler deadline registered (default)
[ 1.377944] io scheduler cfq registered
[ 1.381820] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
[ 1.383633] pciehp: PCI Express Hot Plug Controller Driver version: 0.4
[ 1.454616] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[ 1.457374] ACPI: Power Button [PWRF]
[ 1.544512] GHES: HEST is not enabled!
[ 1.546389] ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 10
[ 1.548467] ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 10
[ 1.550488] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled
[ 1.576865] serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[ 1.701117] serial8250: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
[ 1.728275] 00:05: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[ 1.752534] 00:06: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
[ 1.760444] Linux agpgart interface v0.103
[ 1.769514] brd: module loaded
[ 1.771549] loop: module loaded
[ 2.060045] Refined TSC clocksource calibration: 2394.000 MHz.
[ 2.107412] vda: vda1
[ 2.468051] vdb: unknown partition table
[ 2.500090] scsi0 : ata_piix
[ 2.508227] scsi1 : ata_piix
[ 2.509408] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc1c0 irq 14
[ 2.511804] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc1c8 irq 15
[ 2.515247] Fixed MDIO Bus: probed
[ 2.516567] tun: Universal TUN/TAP device driver, 1.6
[ 2.518165] tun: (C) 1999-2004 Max Krasnyansky <email address hidden>
[ 2.524213] PPP generic driver version 2.4.2
[ 2.532062] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 2.534093] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[ 2.535969] uhci_hcd: USB Universal Host Controller Interface driver
[ 2.544134] uhci_hcd 0000:00:01.2: UHCI Host Controller
[ 2.546053] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
[ 2.749962] uhci_hcd 0000:00:01.2: irq 11, io base 0x0000c180
[ 2.805601] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001
[ 2.807841] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 2.812730] usb usb1: Product: UHCI Host Controller
[ 2.814568] usb usb1: Manufacturer: Linux 3.5.0-36-generic uhci_hcd
[ 2.818140] usb usb1: SerialNumber: 0000:00:01.2
[ 2.820008] hub 1-0:1.0: USB hub found
[ 2.821489] hub 1-0:1.0: 2 ports detected
[ 2.823189] usbcore: registered new interface driver libusual
[ 2.901088] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[ 2.920456] serio: i8042 KBD port at 0x60,0x64 irq 1
[ 2.922178] serio: i8042 AUX port at 0x60,0x64 irq 12
[ 2.924007] mousedev: PS/2 mouse device common for all mice
[ 2.926586] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1
[ 2.929677] rtc_cmos 00:01: RTC can wake from S4
[ 2.931946] rtc_cmos 00:01: rtc core: registered rtc_cmos as rtc0
[ 2.934141] rtc0: alarms up to one day, 114 bytes nvram, hpet irqs
[ 2.936228] device-mapper: uevent: version 1.0.3
[ 2.983878] device-mapper: ioctl: 4.22.0-ioctl (2011-10-19) initialised: <email address hidden>
[ 2.987132] cpuidle: using governor ladder
[ 2.988793] cpuidle: using governor menu
[ 2.990326] EFI Variables Facility v0.08 2004-May-17
[ 2.996416] ashmem: initialized
[ 3.112828] TCP: cubic registered
[ 3.114358] NET: Registered protocol family 10
[ 3.117155] NET: Registered protocol family 17
[ 3.118801] Key type dns_resolver registered
[ 3.465389] usb 1-1: new full-speed USB device number 2 using uhci_hcd
[ 4.333664] registered taskstats version 1
[ 4.445162] Freeing initrd memory: 18476k freed
[ 4.765859] Key type trusted registered
[ 5.459163] Key type encrypted registered
[ 5.468823] Magic number: 9:568:883
[ 5.508555] rtc_cmos 00:01: setting system clock to 2013-08-14 11:51:57 UTC (1376481117)
[ 5.532350] BIOS EDD facility v0.16 2004-Jun-25, 0 devices found
[ 5.534329] EDD information not available.
[ 5.537647] Freeing unused kernel memory: 932k freed
[ 5.539729] Write protecting the kernel read-only data: 12288k
[ 5.546311] Freeing unused kernel memory: 1468k freed
[ 6.102661] Freeing unused kernel memory: 1132k freed
Loading, please wait...
[ 6.896710] usb 1-1: New USB device found, idVendor=0627, idProduct=0001
[ 6.898922] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=5
[ 6.906007] usb 1-1: Product: QEMU USB Tablet
[ 6.911417] usb 1-1: Manufacturer: QEMU 1.0
[ 6.912938] usb 1-1: SerialNumber: 42
[ 6.973497] udevd[88]: starting version 175
[ 7.501545] 8139cp: 8139cp: 10/100 PCI Ethernet driver v1.3 (Mar 22, 2004)
[ 8.187454] usbcore: registered new interface driver usbhid
[ 8.189319] usbhid: USB HID core driver
[ 8.459567] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11
[ 8.593574] input: QEMU 1.0 QEMU USB Tablet as /devices/pci0000:00/0000:00:01.2/usb1/1-1/1-1:1.0/input/input2
[ 8.598345] FDC 0 is a S82078B
[ 8.601017] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v0.01 Pointer [QEMU 1.0 QEMU USB Tablet] on usb-0000:00:01.2-1/input0
[ 8.740930] 8139cp 0000:00:03.0: eth0: RTL-8139C+ at 0xffffc900008ac000, fa:16:3e:4e:22:b2, IRQ 11
[ 10.282863] 8139too: 8139too Fast Ethernet driver 0.9.28
error: unexpectedly disconnected from boot status daemon
Begin: Loading essential drivers ... done.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ... done.
Begin: Running /scripts/local-premount ... done.
[ 20.346068] EXT4-fs (vda1): mounted filesystem with ordered data mode. Opts: (null)
Begin: Running /scripts/local-bottom ... [ 21.583052] vda: vda1
GROWROOT: CHANGED: partition=1 start=16065 old: size=3052350 end=3068415 new: size=20948760,end=20964825
[ 24.501466] EXT4-fs (vda1): mounted filesystem with ordered data mode. Opts: (null)
done.
done.
Begin: Running /scripts/init-bottom ... done.
[ 38.061029] EXT4-fs (vda1): re-mounted. Opts: (null)
mountall: Disconnected from Plymouth
Cloud-init v. 0.7 running 'init-local' at Wed, 14 Aug 2013 11:53:31 +0000. Up 99.77 seconds.
Cloud-init v. 0.7 running 'init' at Wed, 14 Aug 2013 11:53:41 +0000. Up 109.94 seconds.
ci-info: ++++++++++++++++++++++++++Net device info++++++++++++++++++++++++++
ci-info: +--------+------+-----------+-----------------+-------------------+
ci-info: | Device | Up | Address | Mask | Hw-Address |
ci-info: +--------+------+-----------+-----------------+-------------------+
ci-info: | lo | True | 127.0.0.1 | 255.0.0.0 | . |
ci-info: | eth0 | True | 10.1.1.8 | 255.255.255.224 | fa:16:3e:4e:22:b2 |
ci-info: +--------+------+-----------+-----------------+-------------------+
ci-info: +++++++++++++++++++++++++++++++Route info+++++++++++++++++++++++++++++++
ci-info: +-------+-------------+----------+-----------------+-----------+-------+
ci-info: | Route | Destination | Gateway | Genmask | Interface | Flags |
ci-info: +-------+-------------+----------+-----------------+-----------+-------+
ci-info: | 0 | 0.0.0.0 | 10.1.1.3 | 0.0.0.0 | eth0 | UG |
ci-info: | 1 | 10.1.1.0 | 0.0.0.0 | 255.255.255.224 | eth0 | U |
ci-info: +-------+-------------+----------+-----------------+-----------+-------+
2013-08-14 11:54:57,113 - url_helper.py[WARNING]: Calling 'http://169.254.169.254/2009-04-04/meta-data/instance-id' failed [65/120s]: socket timeout [timed out]
2013-08-14 11:55:58,775 - url_helper.py[WARNING]: Calling 'http://169.254.169.254/2009-04-04/meta-data/instance-id' failed [126/120s]: socket timeout [timed out]
2013-08-14 11:55:58,903 - DataSourceEc2.py[CRITICAL]: Giving up on md from ['http://169.254.169.254/2009-04-04/meta-data/instance-id'] after 127 seconds
Generating public/private rsa key pair.
Your identification has been saved in /etc/ssh/ssh_host_rsa_key.
Your public key has been saved in /etc/ssh/ssh_host_rsa_key.pub.
The key fingerprint is:
c2:de:26:8b:b3:13:69:2b:23:0a:b1:37:ea:4c:21:cf root@ubuntu
The key's randomart image is:
+--[ RSA 2048]----+
| |
| |
| |
| . |
|o. .o S |
|.=. +. o |
|o.E. oo o |
|=oo.+. + |
|=+ oo+. |
+-----------------+
Generating public/private dsa key pair.
Your identification has been saved in /etc/ssh/ssh_host_dsa_key.
Your public key has been saved in /etc/ssh/ssh_host_dsa_key.pub.
The key fingerprint is:
95:a7:36:d8:5a:7a:9c:b7:74:f5:8a:e1:5a:d6:88:c1 root@ubuntu
The key's randomart image is:
+--[ DSA 1024]----+
| |
| . |
| o . |
| = o |
| S E .|
| * = o ..|
| o = B o .|
| . * = . |
| ..+ . |
+-----------------+
Generating public/private ecdsa key pair.
Your identification has been saved in /etc/ssh/ssh_host_ecdsa_key.
Your public key has been saved in /etc/ssh/ssh_host_ecdsa_key.pub.
The key fingerprint is:
df:1c:85:e1:14:1b:9e:cd:85:29:99:41:da:d2:4a:f7 root@ubuntu
The key's randomart image is:
+--[ECDSA 256]---+
| .B= o.|
| B+Oo. |
| + X.+ |
| . + o |
| S . . E |
| . o . |
| . o |
| |
| |
+-----------------+
Cloud-init v. 0.7 running 'modules:config' at Wed, 14 Aug 2013 11:56:38 +0000. Up 286.90 seconds.
 * Starting AppArmor profiles [80G Skipping profile in /etc/apparmor.d/disable: usr.sbin.rsyslogd
[74G[ OK ]
[74G[ OK ]g iSCSI initiator service iscsid [80G
 * Setting up iSCSI targets [80G
iscsiadm: No records found
[74G[ OK ]
[74G[ OK ]g network filesystems [80G
landscape-client is not configured, please run landscape-config.
+ touch /var/log/first-boot.d.log
+ chmod 0600 /var/log/first-boot.d.log
+ run-parts /etc/first-boot.d
+ rm -fr /etc/first-boot.d
+ rm -f /etc/rc.local
+ '[' -f /etc/rc.local.REAL ']'
+ mv /etc/rc.local.REAL /etc/rc.local
+ exit 0
Generating locales...
  en_US.UTF-8... done
Generation complete.
Cloud-init v. 0.7 running 'modules:final' at Wed, 14 Aug 2013 11:58:04 +0000. Up 372.04 seconds.
ci-info: no authorized ssh keys fingerprints found for user ubuntu.ci-info: no authorized ssh keys fingerprints found for user ubuntu.ec2:
ec2: #############################################################
ec2: -----BEGIN SSH HOST KEY FINGERPRINTS-----
ec2: 1024 95:a7:36:d8:5a:7a:9c:b7:74:f5:8a:e1:5a:d6:88:c1 root@ubuntu (DSA)
ec2: 256 df:1c:85:e1:14:1b:9e:cd:85:29:99:41:da:d2:4a:f7 root@ubuntu (ECDSA)
ec2: 2048 c2:de:26:8b:b3:13:69:2b:23:0a:b1:37:ea:4c:21:cf root@ubuntu (RSA)
ec2: -----END SSH HOST KEY FINGERPRINTS-----
ec2: #############################################################
-----BEGIN SSH HOST KEY KEYS-----
ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBBluwxdspR0pFKw3xPHt4cdLQYkO6KR57LCa4pfxy0t+nK8txHibKfLghPrzq2qwCPsMIWMRsXTYK3eKvRi8O8A= root@ubuntu
ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDmK436gQGlasR5yRATJwcZ7uEaB2ddndjszUKwbrjcZXPwHrlxa0SlpFf/n+YSW6v4Zu7UXgYHG5/UtvsjWKpU+H8KHWHzNyB4bgDvqQNEfV/XiCKhnSETba+9l7vx3Jj3YKl7GXrihhjObpQ6stvInMiW0PpnQNimHqCrkKBu0o8+N6kaUJrAbeBillpzLBSTuVoWLdHu9Wr715hIfpU3yzJKsDANXhnERr7Eu7J4g4oAQeAx7+DfCePowqYM1BU3zNg7ZEnkweIl1FCfUBNEE5js3HHx2oW6OZl+Djt89c6pKf6IWHMnDsLzzBGfHt1ZONdR3L4b0AlNmD84Efnf root@ubuntu
-----END SSH HOST KEY KEYS-----
Cloud-init v. 0.7 finished at Wed, 14 Aug 2013 11:58:04 +0000. Datasource DataSourceNone. Up 372.38 seconds
2013-08-14 11:58:04,384 - cc_final_message.py[WARNING]: Used fallback datasource
]

Nova Console-log for worker node ---- >

//////////////////////////////////////////////////////////////////

[.............................

  0.545048] vgaarb: bridge control possible 0000:00:02.0
[ 0.548420] SCSI subsystem initialized
[ 0.550117] ACPI: bus type usb registered
[ 0.552103] usbcore: registered new interface driver usbfs
[ 0.553832] usbcore: registered new interface driver hub
[ 0.556189] usbcore: registered new device driver usb
[ 0.558023] PCI: Using ACPI for IRQ routing
[ 0.562213] NetLabel: Initializing
[ 0.564050] NetLabel: domain hash size = 128
[ 0.565599] NetLabel: protocols = UNLABELED CIPSOv4
[ 0.568075] NetLabel: unlabeled traffic allowed by default
[ 0.569992] HPET: 3 timers in total, 0 timers will be used for per-cpu timer
[ 0.572083] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
[ 0.574110] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
[ 0.580138] Switching to clocksource kvm-clock
[ 0.629017] AppArmor: AppArmor Filesystem Enabled
[ 0.631122] pnp: PnP ACPI init
[ 0.632339] ACPI: bus type pnp registered
[ 0.634654] pnp: PnP ACPI: found 8 devices
[ 0.636084] ACPI: ACPI bus type pnp unregistered
[ 0.644401] NET: Registered protocol family 2
[ 0.645926] IP route cache hash table entries: 65536 (order: 7, 524288 bytes)
[ 0.649893] TCP established hash table entries: 262144 (order: 10, 4194304 bytes)
[ 0.662305] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes)
[ 1.063239] TCP: Hash tables configured (established 262144 bind 65536)
[ 1.065271] TCP: reno registered
[ 1.066461] UDP hash table entries: 1024 (order: 3, 32768 bytes)
[ 1.069345] UDP-Lite hash table entries: 1024 (order: 3, 32768 bytes)
[ 1.071410] NET: Registered protocol family 1
[ 1.072883] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[ 1.074699] pci 0000:00:01.0: PIIX3: Enabling Passive Release
[ 1.077155] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[ 1.079699] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11
[ 1.122762] audit: initializing netlink socket (disabled)
[ 1.124533] type=2000 audit(1376481113.124:1): initialized
[ 1.146679] Trying to unpack rootfs image as initramfs...
[ 1.260863] HugeTLB registered 2 MB page size, pre-allocated 0 pages
[ 1.266361] VFS: Disk quotas dquot_6.5.2
[ 1.267772] Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[ 1.270515] fuse init (API version 7.19)
[ 1.271938] msgmni has been set to 3963
[ 1.274120] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[ 1.276654] io scheduler noop registered
[ 1.277990] io scheduler deadline registered (default)
[ 1.279628] io scheduler cfq registered
[ 1.281231] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
[ 1.283001] pciehp: PCI Express Hot Plug Controller Driver version: 0.4
[ 1.286093] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[ 1.288583] ACPI: Power Button [PWRF]
[ 1.291751] GHES: HEST is not enabled!
[ 1.293799] ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 10
[ 1.295978] ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 10
[ 1.325144] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled
[ 1.349465] serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[ 1.394806] serial8250: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
[ 1.456339] 00:05: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[ 1.535754] 00:06: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
[ 1.571399] Linux agpgart interface v0.103
[ 1.576246] brd: module loaded
[ 1.578395] loop: module loaded
[ 1.669599] vda: vda1
[ 2.234816] Refined TSC clocksource calibration: 2394.003 MHz.
[ 2.322451] vdb: unknown partition table
[ 2.526950] scsi0 : ata_piix
[ 2.571421] scsi1 : ata_piix
[ 2.572682] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc1c0 irq 14
[ 2.574749] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc1c8 irq 15
[ 2.587358] Fixed MDIO Bus: probed
[ 2.588692] tun: Universal TUN/TAP device driver, 1.6
[ 2.590301] tun: (C) 1999-2004 Max Krasnyansky <email address hidden>
[ 2.592256] PPP generic driver version 2.4.2
[ 2.593714] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 2.595953] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[ 2.597894] uhci_hcd: USB Universal Host Controller Interface driver
[ 2.599911] uhci_hcd 0000:00:01.2: UHCI Host Controller
[ 2.602058] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
[ 2.825596] uhci_hcd 0000:00:01.2: irq 11, io base 0x0000c180
[ 2.876567] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001
[ 2.878949] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 2.882633] usb usb1: Product: UHCI Host Controller
[ 2.884555] usb usb1: Manufacturer: Linux 3.5.0-36-generic uhci_hcd
[ 2.890140] usb usb1: SerialNumber: 0000:00:01.2
[ 2.899940] hub 1-0:1.0: USB hub found
[ 2.913245] hub 1-0:1.0: 2 ports detected
[ 2.914970] usbcore: registered new interface driver libusual
[ 2.932286] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[ 3.174045] serio: i8042 KBD port at 0x60,0x64 irq 1
[ 3.175811] serio: i8042 AUX port at 0x60,0x64 irq 12
[ 3.184181] mousedev: PS/2 mouse device common for all mice
[ 3.210569] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1
[ 3.213822] rtc_cmos 00:01: RTC can wake from S4
[ 3.220416] rtc_cmos 00:01: rtc core: registered rtc_cmos as rtc0
[ 3.266165] usb 1-1: new full-speed USB device number 2 using uhci_hcd
[ 3.527125] hpet1: lost 2 rtc interrupts
[ 4.631645] rtc0: alarms up to one day, 114 bytes nvram, hpet irqs
[ 4.634386] device-mapper: uevent: version 1.0.3
[ 4.635959] device-mapper: ioctl: 4.22.0-ioctl (2011-10-19) initialised: <email address hidden>
[ 4.638831] cpuidle: using governor ladder
[ 4.640246] cpuidle: using governor menu
[ 4.641608] EFI Variables Facility v0.08 2004-May-17
[ 4.703225] ashmem: initialized
[ 4.704620] TCP: cubic registered
[ 4.758452] NET: Registered protocol family 10
[ 5.666175] NET: Registered protocol family 17
[ 5.748298] Key type dns_resolver registered
[ 5.817371] usb 1-1: New USB device found, idVendor=0627, idProduct=0001
[ 5.933739] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=5
[ 5.935883] usb 1-1: Product: QEMU USB Tablet
[ 5.937377] usb 1-1: Manufacturer: QEMU 1.0
[ 5.938806] usb 1-1: SerialNumber: 42
[ 6.305794] registered taskstats version 1
[ 6.484833] Freeing initrd memory: 18476k freed
[ 6.984644] Key type trusted registered
[ 6.994136] Key type encrypted registered
[ 7.003795] Magic number: 9:568:883
[ 7.028949] rtc_cmos 00:01: setting system clock to 2013-08-14 11:51:58 UTC (1376481118)
[ 7.032084] BIOS EDD facility v0.16 2004-Jun-25, 0 devices found
[ 7.034207] EDD information not available.
[ 7.099575] Freeing unused kernel memory: 932k freed
[ 7.101669] Write protecting the kernel read-only data: 12288k
[ 7.107900] Freeing unused kernel memory: 1468k freed
[ 7.113746] Freeing unused kernel memory: 1132k freed
Loading, please wait...
[ 7.693344] udevd[88]: starting version 175
[ 9.821507] usbcore: registered new interface driver usbhid
[ 11.149419] usbhid: USB HID core driver
[ 11.634797] 8139cp: 8139cp: 10/100 PCI Ethernet driver v1.3 (Mar 22, 2004)
[ 20.620193] input: QEMU 1.0 QEMU USB Tablet as /devices/pci0000:00/0000:00:01.2/usb1/1-1/1-1:1.0/input/input2
[ 20.849425] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v0.01 Pointer [QEMU 1.0 QEMU USB Tablet] on usb-0000:00:01.2-1/input0
[ 21.001048] FDC 0 is a S82078B
[ 21.075144] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11
[ 21.081246] 8139cp 0000:00:03.0: eth0: RTL-8139C+ at 0xffffc900008ac000, fa:16:3e:74:a8:5c, IRQ 11
[ 21.087646] 8139too: 8139too Fast Ethernet driver 0.9.28
error: unexpectedly disconnected from boot status daemon
Begin: Loading essential drivers ... done.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ... done.
Begin: Running /scripts/local-premount ... done.
[ 26.380350] EXT4-fs (vda1): mounted filesystem with ordered data mode. Opts: (null)
Begin: Running /scripts/local-bottom ... [ 40.504733] vda: vda1
GROWROOT: CHANGED: partition=1 start=16065 old: size=3052350 end=3068415 new: size=20948760,end=20964825
[ 43.386164] EXT4-fs (vda1): mounted filesystem with ordered data mode. Opts: (null)
done.
done.
Begin: Running /scripts/init-bottom ... done.
[ 56.234453] EXT4-fs (vda1): re-mounted. Opts: (null)
mountall: Plymouth command failed
mountall: Disconnected from Plymouth
Cloud-init v. 0.7 running 'init-local' at Wed, 14 Aug 2013 11:53:36 +0000. Up 104.59 seconds.
Cloud-init v. 0.7 running 'init' at Wed, 14 Aug 2013 11:53:41 +0000. Up 110.26 seconds.
ci-info: ++++++++++++++++++++++++++Net device info++++++++++++++++++++++++++
ci-info: +--------+------+-----------+-----------------+-------------------+
ci-info: | Device | Up | Address | Mask | Hw-Address |
ci-info: +--------+------+-----------+-----------------+-------------------+
ci-info: | lo | True | 127.0.0.1 | 255.0.0.0 | . |
ci-info: | eth0 | True | 10.1.1.7 | 255.255.255.224 | fa:16:3e:74:a8:5c |
ci-info: +--------+------+-----------+-----------------+-------------------+
ci-info: +++++++++++++++++++++++++++++++Route info+++++++++++++++++++++++++++++++
ci-info: +-------+-------------+----------+-----------------+-----------+-------+
ci-info: | Route | Destination | Gateway | Genmask | Interface | Flags |
ci-info: +-------+-------------+----------+-----------------+-----------+-------+
ci-info: | 0 | 0.0.0.0 | 10.1.1.3 | 0.0.0.0 | eth0 | UG |
ci-info: | 1 | 10.1.1.0 | 0.0.0.0 | 255.255.255.224 | eth0 | U |
ci-info: +-------+-------------+----------+-----------------+-----------+-------+
2013-08-14 11:54:41,603 - url_helper.py[WARNING]: Calling 'http://169.254.169.254/2009-04-04/meta-data/instance-id' failed [50/120s]: socket timeout [timed out]
2013-08-14 11:55:58,418 - url_helper.py[WARNING]: Calling 'http://169.254.169.254/2009-04-04/meta-data/instance-id' failed [126/120s]: socket timeout [timed out]
2013-08-14 11:55:58,474 - DataSourceEc2.py[CRITICAL]: Giving up on md from ['http://169.254.169.254/2009-04-04/meta-data/instance-id'] after 127 seconds
Generating public/private rsa key pair.
Your identification has been saved in /etc/ssh/ssh_host_rsa_key.
Your public key has been saved in /etc/ssh/ssh_host_rsa_key.pub.
The key fingerprint is:
75:1e:9c:5c:a9:4e:81:32:f7:dc:87:b6:a2:9b:55:7f root@ubuntu
The key's randomart image is:
+--[ RSA 2048]----+
| . .. |
| o oo.o. |
| +.o*+ . |
| . o=.+ .|
| S o...o |
| o... |
| ... E|
| .o .|
| o. |
+-----------------+
Generating public/private dsa key pair.
Your identification has been saved in /etc/ssh/ssh_host_dsa_key.
Your public key has been saved in /etc/ssh/ssh_host_dsa_key.pub.
The key fingerprint is:
e8:96:ee:e1:97:0a:c3:9d:84:0b:f9:7c:df:03:43:6f root@ubuntu
The key's randomart image is:
+--[ DSA 1024]----+
| |
| |
| |
| . . .. |
| o . o.S. |
| = = oo E |
| B O = |
| B oo.. |
| .=o. .. |
+-----------------+
Generating public/private ecdsa key pair.
Your identification has been saved in /etc/ssh/ssh_host_ecdsa_key.
Your public key has been saved in /etc/ssh/ssh_host_ecdsa_key.pub.
The key fingerprint is:
94:90:5c:61:ab:2f:80:52:ea:9b:e8:b2:cb:1f:65:1a root@ubuntu
The key's randomart image is:
+--[ECDSA 256]---+
| ..o+. |
| oo o |
| . + |
| o . o |
|o .E.o. S |
|.. =. . |
| . o . . |
|+ o . . |
|*B.. |
+-----------------+
 * Starting AppArmor profiles [80G Skipping profile in /etc/apparmor.d/disable: usr.sbin.rsyslogd
Cloud-init v. 0.7 running 'modules:config' at Wed, 14 Aug 2013 11:56:49 +0000. Up 298.44 seconds.
[74G[ OK ]
[74G[ OK ]g iSCSI initiator service iscsid [80G
 * Setting up iSCSI targets [80G
iscsiadm: No records found
[74G[ OK ]
[74G[ OK ]g network filesystems [80G
landscape-client is not configured, please run landscape-config.
+ touch /var/log/first-boot.d.log
+ chmod 0600 /var/log/first-boot.d.log
+ run-parts /etc/first-boot.d
Generating locales...
  en_US.UTF-8... + rm -fr /etc/first-boot.d
+ rm -f /etc/rc.local
+ '[' -f /etc/rc.local.REAL ']'
+ mv /etc/rc.local.REAL /etc/rc.local
+ exit 0
done
Generation complete.
Cloud-init v. 0.7 running 'modules:final' at Wed, 14 Aug 2013 11:58:04 +0000. Up 372.55 seconds.
ci-info: no authorized ssh keys fingerprints found for user ubuntu.ci-info: no authorized ssh keys fingerprints found for user ubuntu.ec2:
ec2: #############################################################
ec2: -----BEGIN SSH HOST KEY FINGERPRINTS-----
ec2: 1024 e8:96:ee:e1:97:0a:c3:9d:84:0b:f9:7c:df:03:43:6f root@ubuntu (DSA)
ec2: 256 94:90:5c:61:ab:2f:80:52:ea:9b:e8:b2:cb:1f:65:1a root@ubuntu (ECDSA)
ec2: 2048 75:1e:9c:5c:a9:4e:81:32:f7:dc:87:b6:a2:9b:55:7f root@ubuntu (RSA)
ec2: -----END SSH HOST KEY FINGERPRINTS-----
ec2: #############################################################
-----BEGIN SSH HOST KEY KEYS-----
ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBNwf7JMAA7E20Q29j+fjMv0/74cPZhU7NT/S1YfvFnehaMp2jy7+1RC+MNWd8kKwY7KUtpNfhKUjF4QMPkUNg4E= root@ubuntu
ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCsVGbLjYR8vZdGbtG2AVUXK6ibcUaL0p5bUXHA5vm9DYhWA+w2fu1Yszl+QUAlzmUaQSwEpmj2/JCfyH5aGtJUyRGl4ppgubCyZmfvtl7kUeBDw1rq7E+edTn1BQMZLbN/oODLqfuY/rjboV1Fd+4Tml7rbcby5hfHMRAzzN/8Gt7sJApuwhgTGIlPTaMkQ66xBFpRYM1N1KH+T3mCkN2VL0vi4561a2rLCmddDYw4HttbNxXlbocj2bJSFXn1/+XV+DsMOioNN58N5EsTDTjPzESbFlpf1znaAO07HESTFLm4x0vB4o7DIdkVgU5roKQio6c+Vvn5pEk/c177+jtT root@ubuntu
-----END SSH HOST KEY KEYS-----
Cloud-init v. 0.7 finished at Wed, 14 Aug 2013 11:58:04 +0000. Datasource DataSourceNone. Up 372.97 seconds
2013-08-14 11:58:04,457 - cc_final_message.py[WARNING]: Used fallback datasource
]

The cluster-instances are connecting via their internal IP using ssh.

The debug log file of savanna --------------->
///////////////////////////////////////////////////////////////////////////////////////////////

(31614) accepted ('10.208.36.50', 35577)
10.208.36.50 - - [14/Aug/2013 17:30:08] "GET /v1.0/11f94438f0f1466d814f2cf5a6f2839a/cluster-templates HTTP/1.1" 200 2649 0.015877
(31614) accepted ('10.208.36.50', 35578)
10.208.36.50 - - [14/Aug/2013 17:30:09] "GET /v1.0/11f94438f0f1466d814f2cf5a6f2839a/images HTTP/1.1" 200 585 0.203048
(31614) accepted ('10.208.36.50', 35589)
10.208.36.50 - - [14/Aug/2013 17:30:09] "GET /v1.0/11f94438f0f1466d814f2cf5a6f2839a/plugins/vanilla/1.1.2 HTTP/1.1" 200 92340 0.030381
(31614) accepted ('10.208.36.50', 35783)
10.208.36.50 - - [14/Aug/2013 17:30:25] "GET /v1.0/11f94438f0f1466d814f2cf5a6f2839a/cluster-templates HTTP/1.1" 200 2649 0.018988
(31614) accepted ('10.208.36.50', 35784)
10.208.36.50 - - [14/Aug/2013 17:30:25] "GET /v1.0/11f94438f0f1466d814f2cf5a6f2839a/images HTTP/1.1" 200 585 0.113088
(31614) accepted ('10.208.36.50', 35793)
10.208.36.50 - - [14/Aug/2013 17:30:25] "GET /v1.0/11f94438f0f1466d814f2cf5a6f2839a/plugins/vanilla/1.1.2 HTTP/1.1" 200 92340 0.015437
(31614) accepted ('10.208.36.50', 35800)
10.208.36.50 - - [14/Aug/2013 17:30:26] "POST /v1.0/11f94438f0f1466d814f2cf5a6f2839a/clusters HTTP/1.1" 202 1288 0.884477
(31614) accepted ('10.208.36.50', 35829)
10.208.36.50 - - [14/Aug/2013 17:30:27] "GET /v1.0/11f94438f0f1466d814f2cf5a6f2839a/clusters HTTP/1.1" 200 4387 0.044614
(31614) accepted ('10.208.36.50', 35855)
10.208.36.50 - - [14/Aug/2013 17:30:27] "GET /v1.0/11f94438f0f1466d814f2cf5a6f2839a/clusters/5a515a4c-2e51-467c-aa32-964223c58ab1 HTTP/1.1" 200 1280 0.154778
2013-08-14 17:30:27.686 31614 WARNING savanna.service.instances [-] Can't start cluster 'tt' (reason: Second simultaneous read on fileno 11 detected. Unless you really know what you're doing, make sure that only one greenthread can read any particular socket. Consider using a pools.Pool. If you do know what you're doing and want to disable this error, call eventlet.debug.hub_prevent_multiple_readers(False))
Traceback (most recent call last):
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/eventlet/hubs/poll.py", line 97, in wait
    readers.get(fileno, noop).cb(fileno)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/eventlet/greenthread.py", line 194, in main
    result = function(*args, **kwargs)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/context.py", line 132, in wrapper
    func(*args, **kwargs)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/service/api.py", line 111, in _provision_cluster
    i.create_cluster(cluster)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/service/instances.py", line 52, in create_cluster
    _rollback_cluster_creation(cluster, ex)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/service/instances.py", line 35, in create_cluster
    _create_instances(cluster)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/service/instances.py", line 106, in _create_instances
    _run_instance(cluster, node_group, idx, aa_groups, userdata)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/service/instances.py", line 165, in _run_instance
    key_name=cluster.user_keypair_id)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/novaclient/v1_1/servers.py", line 638, in create
    **boot_kwargs)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/novaclient/base.py", line 369, in _boot
    return_raw=return_raw, **kwargs)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/novaclient/base.py", line 144, in _create
    _resp, body = self.api.client.post(url, body=body)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/novaclient/client.py", line 232, in post
    return self._cs_request(url, 'POST', **kwargs)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/novaclient/client.py", line 213, in _cs_request
    **kwargs)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/novaclient/client.py", line 195, in _time_request
    resp, body = self.request(url, method, **kwargs)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/novaclient/client.py", line 166, in request
    **kwargs)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/requests/sessions.py", line 335, in request
    resp = self.send(prep, **send_kwargs)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/requests/sessions.py", line 438, in send
    r = adapter.send(request, **kwargs)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/requests/adapters.py", line 292, in send
    timeout=timeout
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/requests/packages/urllib3/connectionpool.py", line 428, in urlopen
    body=body, headers=headers)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/requests/packages/urllib3/connectionpool.py", line 288, in _make_request
    httplib_response = conn.getresponse(buffering=True)
  File "/usr/lib/python2.7/httplib.py", line 1030, in getresponse
    response.begin()
  File "/usr/lib/python2.7/httplib.py", line 407, in begin
    version, status, reason = self._read_status()
  File "/usr/lib/python2.7/httplib.py", line 365, in _read_status
    line = self.fp.readline()
  File "/usr/lib/python2.7/socket.py", line 447, in readline
    data = self._sock.recv(self._rbufsize)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/eventlet/greenio.py", line 262, in recv
    timeout_exc=socket.timeout("timed out"))
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/eventlet/hubs/__init__.py", line 151, in trampoline
    listener = hub.add(hub.READ, fileno, current.switch)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/eventlet/hubs/epolls.py", line 48, in add
    listener = BaseHub.add(self, evtype, fileno, cb)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/eventlet/hubs/hub.py", line 126, in add
    evtype, fileno, evtype))
RuntimeError: Second simultaneous read on fileno 11 detected. Unless you really know what you're doing, make sure that only one greenthread can read any particular socket. Consider using a pools.Pool. If you do know what you're doing and want to disable this error, call eventlet.debug.hub_prevent_multiple_readers(False)
Removing descriptor: 20
(31614) accepted ('10.208.36.50', 35909)
10.208.36.50 - - [14/Aug/2013 17:30:30] "GET /v1.0/11f94438f0f1466d814f2cf5a6f2839a/clusters/5a515a4c-2e51-467c-aa32-964223c58ab1 HTTP/1.1" 200 1612 0.023379
(31614) accepted ('10.208.36.50', 36048)
10.208.36.50 - - [14/Aug/2013 17:30:40] "GET /v1.0/11f94438f0f1466d814f2cf5a6f2839a/clusters HTTP/1.1" 200 4719 0.032693
(31614) accepted ('10.208.36.50', 36407)
10.208.36.50 - - [14/Aug/2013 17:31:09] "GET /v1.0/11f94438f0f1466d814f2cf5a6f2839a/clusters HTTP/1.1" 200 4719 0.027751
2013-08-15 11:04:47.607 31614 WARNING savanna.service.instances [-] Can't start cluster 'cluster-1' (reason: Unauthorized (HTTP 401))
2013-08-15 11:04:48.039 31614 ERROR root [-] Original exception being dropped: ['Traceback (most recent call last):\n', ' File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/service/instances.py", line 39, in create_cluster\n _await_instances(cluster)\n', ' File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/service/instances.py", line 208, in _await_instances\n if not _check_if_up(instance):\n', ' File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/service/instances.py", line 217, in _check_if_up\n server = nova.get_instance_info(instance)\n', ' File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/utils/openstack/nova.py", line 69, in get_instance_info\n return client().servers.get(instance.instance_id)\n', ' File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/novaclient/v1_1/servers.py", line 365, in get\n return self._get("/servers/%s" % base.getid(server), "server")\n', ' File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/novaclient/base.py", line 139, in _get\n _resp, body = self.api.client.get(url)\n', ' File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/novaclient/client.py", line 229, in get\n return self._cs_request(url, \'GET\', **kwargs)\n', ' File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/novaclient/client.py", line 226, in _cs_request\n raise e\n', 'Unauthorized: Unauthorized (HTTP 401)\n']
Traceback (most recent call last):
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/eventlet/hubs/poll.py", line 97, in wait
    readers.get(fileno, noop).cb(fileno)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/eventlet/greenthread.py", line 194, in main
    result = function(*args, **kwargs)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/context.py", line 132, in wrapper
    func(*args, **kwargs)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/service/api.py", line 111, in _provision_cluster
    i.create_cluster(cluster)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/service/instances.py", line 52, in create_cluster
    _rollback_cluster_creation(cluster, ex)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/service/instances.py", line 292, in _rollback_cluster_creation
    _shutdown_instances(cluster, True)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/service/instances.py", line 321, in _shutdown_instances
    _shutdown_instance(instance)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/savanna/service/instances.py", line 327, in _shutdown_instance
    nova.client().servers.delete(instance.instance_id)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/novaclient/v1_1/servers.py", line 668, in delete
    self._delete("/servers/%s" % base.getid(server))
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/novaclient/base.py", line 153, in _delete
    _resp, _body = self.api.client.delete(url)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/novaclient/client.py", line 238, in delete
    return self._cs_request(url, 'DELETE', **kwargs)
  File "/etc/init.d/savanna-venv/local/lib/python2.7/site-packages/novaclient/client.py", line 226, in _cs_request
    raise e
Unauthorized: Unauthorized (HTTP 401)
Removing descriptor: 48
(31614) accepted ('10.208.36.50', 50014)
10.208.36.50 - - [16/Aug/2013 08:39:33] "GET /v1.0/11f94438f0f1466d814f2cf5a6f2839a/clusters HTTP/1.1" 200 4888 0.569258

The savanna log for cluster created using REST is from cluster-1.

Please ignore the previous log for "cluster-tt."

Sorry for pasting some irrelevant information in log file description.

Sarita,

since you can get access from Savanna host to instances through internal IP - change in the savanna.conf:
use_floating_ips=False

Thanks Alexander Rubtsov, that solved my question.

Alexander,

I did the changes in savanna.conf (use_floating_ips=False) and launch a new cluster named - Cluster-2.

Now my cluster is in ACTIVE State.

Thanks a lot for patience and helping me out . :) :) :) :) :)

Can u please help me about the access of the instances. What is the password of that image for username ubuntu i.e. http://savanna-files.mirantis.com/savanna-0.2-vanilla-1.1.2-ubuntu-12.10.qcow2

and I am also unable to access the instance when i am using Web UI for MAP reduce and HDFS.

Is it necessary to use swift.?

Sarita,

You can access to instances using ssh-key that you specified when you create a cluster.
Using Swift is optional. You can don't use it if you want.

What to do if I have to use floating ip as managed ip .

when I have mention the option using_floating_ips=True,cluster goes into waiting state. So what to do for that to get rid out of it ?

Alexander Rubstsov ,

Thanks a lot. Thanks for listening me patiently and solving my problem.

My Cluster is now in ACTIVE state and i am unable to access my instance using web UI. :) :) :) :)

I am facing the same problem .
I am using savanna 0.3 and neutron network. The cluster is in waiting state for 24 hours after which the keystone token is invalid.
Sometimes i can log in to the instances. But HDFS is not working in the system.
Below is the hadoop report log
hadoop dfsadmin -report
report: FileSystem file:/// is not a distributed file system
Usage: java DFSAdmin [-report]

Here is my savanna configuration file

host="localhost"
port=8386

# Address and credentials that will be used to check auth tokens
os_auth_host=10.2.1.3
os_auth_port=5000
os_admin_username=admin
os_admin_password=*********
os_admin_tenant_name=admin

use_floating_ips=False

use_neutron=True

debug=true

verbose=true

plugins=vanilla,hdp

[plugin:vanilla]
plugin_class=savanna.plugins.vanilla.plugin:VanillaProvider

[plugin:hdp]
plugin_class=savanna.plugins.hdp.ambariplugin:AmbariPlugin

[database]
connection=sqlite:///savanna.sqlite

dikshith,

According to config you are using neutron (use_neutron=True) and doesn't use floating IPs (use_floating_ips=False). In this case host with Savanna need to have direct access to VMs via private network (usually it has not). You can always see IP address Savanna trying to use in cluster details (management IP column). Please check that you can ssh to VMs from the host with Savanna after VMs started up.

What version of savanna do you use? Master branch contains fix with netns proxy support (https://review.openstack.org/#/c/52997/). Enabling it (use_namespaces=True) could help you with the issue.