Duplex: CirrOS VM login takes too much time, and throw different log errors
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
StarlingX |
Invalid
|
Medium
|
Gongjun Song |
Bug Description
Brief Description
-----------------
After launching a VM with CirrOS, an with a running VM state. If you try to login into the VM using virsh,
this operation takes ~5 minutes, and it throws a lot of errors in the console.
Severity
--------
<Minor: System/Feature is usable with minor issue>
Steps to Reproduce
------------------
1.- Follow the instructions described here to setup a StarlingX duplex configuration:
https:/
2.- Download a CirrOS image from here:
wget http://
3.- Create an Image (as root user _not_ as keystone_admin)
openstack image create --container-format bare --disk-format qcow2 --file cirros-
4.- Create a VM
openstack server create --image cirros --flavor m1.tiny --network public-net0 vm1
5.- List the VMs running
sudo virsh list
6.- Login into the previously created VM
sudo virsh consle <ID>
Expected Behavior
------------------
You should be able to see the login prompt from CirrOS after few seconds (5 or less).
Actual Behavior
----------------
Actually it takes ~5 minutes to see the CirrOS login console and several error messages are sent out to the CirrOS login console. Even that using 'openstack server list' you will be able to see an IP address, if you login into the VM you aren't getting the listed IP inside the VM.
Reproducibility
---------------
<Reproducible> All the times
System Configuration
-------
<Two node system> Duplex
Branch/Pull Time/Commit
-------
[sysadmin@
###
### StarlingX
### Built from master
###
OS="centos"
SW_VERSION="19.01"
BUILD_TARGET="Host Installer"
BUILD_TYPE="Formal"
BUILD_ID=
JOB="STX_
<email address hidden>"
BUILD_NUMBER="166"
BUILD_HOST=
BUILD_DATE=
Last Pass
---------
BUILD_DATE=
Timestamp/Logs
--------------
controller-0:~# sudo virsh list
Id Name State
-------
2 instance-00000004 running
controller-0:~# sudo virsh console 2
Connected to domain instance-00000004
Escape character is ^]
Usage: /sbin/cirros-dhcpc <up|down>
No lease, failing
WARN: /etc/rc3.
checking http://
failed 1/20: up 180.95. request failed
failed 2/20: up 182.98. request failed
failed 3/20: up 184.99. request failed
failed 4/20: up 186.99. request failed
failed 5/20: up 188.99. request failed
failed 6/20: up 191.00. request failed
failed 7/20: up 193.00. request failed
failed 8/20: up 195.01. request failed
failed 9/20: up 197.01. request failed
failed 10/20: up 199.02. request failed
failed 11/20: up 201.02. request failed
failed 12/20: up 203.03. request failed
failed 13/20: up 205.03. request failed
failed 14/20: up 207.04. request failed
failed 15/20: up 209.04. request failed
failed 16/20: up 211.04. request failed
failed 17/20: up 213.05. request failed
failed 18/20: up 215.05. request failed
failed 19/20: up 217.06. request failed
failed 20/20: up 219.06. request failed
failed to read iid from metadata. tried 20
failed to get instance-id of datasource
Top of dropbear init script
Starting dropbear sshd: failed to get instance-id of datasource
OK
GROWROOT: CHANGED: partition=1 start=18432 old: size=71647 end=90079 new: size=2078687,
=== system information ===
Platform: OpenStack Foundation OpenStack Nova
Container: none
Arch: x86_64
CPU(s): 1 @ 2593.898 MHz
Cores/Sockets/
Virt-type:
RAM Size: 488MB
Disks:
NAME MAJ:MIN SIZE LABEL MOUNTPOINT
vda 253:0 1073741824
vda1 253:1 1064287744 cirros-rootfs /
vda15 253:15 8388608
=== sshd host keys ===
-----BEGIN SSH HOST KEY KEYS-----
ssh-rsa AAAAB3NzaC1yc2E
ssh-dss AAAAB3NzaC1kc3M
-----END SSH HOST KEY KEYS-----
=== network info ===
if-info: lo,up,127.0.0.1,8,,
if-info: eth0,up,
ip-route6:fe80::/64 dev eth0 metric 256
ip-route6:
ip-route6:ff00::/8 dev eth0 metric 256
ip-route6:
=== datasource: None None ===
=== cirros: current=0.4.0 uptime=221.84 ===
=== pinging gateway failed, debugging connection ===
############ debug start ##############
### /etc/init.d/sshd start
Top of dropbear init script
Starting dropbear sshd: failed to get instance-id of datasource
FAIL
### ifconfig -a
eth0 Link encap:Ethernet HWaddr FA:16:3E:18:BA:53
inet6 addr: fe80::f816:
UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
RX packets:0 errors:0 dropped:0 overruns:0 frame:0
TX packets:10 errors:0 dropped:0 overruns:0 carrier:0
RX bytes:0 (0.0 B) TX bytes:1332 (1.3 KiB)
lo Link encap:Local Loopback
inet addr:127.0.0.1 Mask:255.0.0.0
inet6 addr: ::1/128 Scope:Host
UP LOOPBACK RUNNING MTU:65536 Metric:1
RX packets:12 errors:0 dropped:0 overruns:0 frame:0
TX packets:12 errors:0 dropped:0 overruns:0 carrier:0
RX bytes:1020 (1020.0 B) TX bytes:1020 (1020.0 B)
### route -n
Kernel IP routing table
Destination Gateway Genmask Flags Metric Ref Use Iface
### cat /etc/resolv.conf
cat: can't open '/etc/resolv.conf': No such file or directory
### gateway not found
/sbin/cirros-
### pinging nameservers
### uname -a
Linux cirros 4.4.0-28-generic #47-Ubuntu SMP Fri Jun 24 10:09:13 UTC 2016 x86_64 GNU/Linux
### lsmod
Module Size Used by Not tainted
nls_iso8859_1 16384 0
isofs 40960 0
ip_tables 24576 0
x_tables 36864 1 ip_tables
pcnet32 45056 0
8139cp 28672 0
mii 16384 2 pcnet32,8139cp
ne2k_pci 16384 0
8390 20480 1 ne2k_pci
e1000 135168 0
virtio_scsi 20480 0
### dmesg | tail
[ 1.162710] random: dd urandom read with 5 bits of entropy available
[ 1.258431] usb 1-1: new full-speed USB device number 2 using uhci_hcd
[ 1.419174] usb 1-1: New USB device found, idVendor=0627, idProduct=0001
[ 1.419182] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=5
[ 1.419187] usb 1-1: Product: QEMU USB Tablet
[ 1.419191] usb 1-1: Manufacturer: QEMU
[ 1.419195] usb 1-1: SerialNumber: 42
[ 1.750484] tsc: Refined TSC clocksource calibration: 2593.898 MHz
[ 1.750488] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2563b7b6e37, max_idle_ns: 440795209024 ns
[ 222.089354] EXT4-fs (vda1): resizing filesystem from 32768 to 1039340 blocks
### tail -n 25 /var/log/messages
Jul 4 18:16:36 cirros kern.info kernel: [ 1.769029] tsc: Refined TSC clocksource calibration: 2593.891 MHz
Jul 4 18:16:36 cirros kern.info kernel: [ 1.769033] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2563b0e36c4, max_idle_ns: 440795206265 ns
Jul 5 12:45:42 cirros syslog.info syslogd started: BusyBox v1.23.2
Jul 5 12:45:42 cirros kern.notice kernel: klogd started: BusyBox v1.23.2 (2017-11-20 02:37:12 UTC)
Jul 5 12:45:42 cirros kern.info kernel: [ 0.000000] Initializing cgroup subsys cpuset
Jul 5 12:45:42 cirros kern.info kernel: [ 0.000000] Initializing cgroup subsys cpu
Jul 5 12:45:42 cirros kern.info kernel: [ 0.000000] Initializing cgroup subsys cpuacct
Jul 5 12:45:42 cirros kern.notice kernel: [ 0.000000] Linux version 4.4.0-28-generic (buildd@lcy01-13) (gcc version 5.3.1 20160413 (Ubuntu 5.3.1-14ubuntu2.1) ) #47-Ubuntu SMP Fri Jun 24 10:09:13 UT C 2016 (Ubuntu 4.4.0-28.47-generic 4.4.13)
Jul 5 12:45:42 cirros kern.info kernel: [ 0.000000] Command line: LABEL=cirros-rootfs ro console=tty1 console=ttyS0
Jul 5 12:45:42 cirros kern.info kernel: [ 0.000000] KERNEL supported cpus:
Jul 5 12:45:42 cirros kern.info kernel: [ 0.000000] Intel GenuineIntel
Jul 5 12:45:42 cirros kern.info kernel: [ 0.000000] AMD AuthenticAMD
Jul 5 12:45:42 cirros kern.info kernel: [ 0.000000] Centaur CentaurHauls
Jul 5 12:45:42 cirros kern.info kernel: [ 0.000000] x86/fpu: Legacy x87 FPU detected.
Jul 5 12:45:42 cirros kern.notice kernel: [ 1.162710] random: dd urandom read with 5 bits of entropy available
Jul 5 12:45:42 cirros kern.info kernel: [ 1.258431] usb 1-1: new full-speed USB device number 2 using uhci_hcd
Jul 5 12:45:42 cirros kern.info kernel: [ 1.419174] usb 1-1: New USB device found, idVendor=0627, idProduct=0001
Jul 5 12:45:42 cirros kern.info kernel: [ 1.419182] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=5
Jul 5 12:45:42 cirros kern.info kernel: [ 1.419187] usb 1-1: Product: QEMU USB Tablet
Jul 5 12:45:42 cirros kern.info kernel: [ 1.419191] usb 1-1: Manufacturer: QEMU
Jul 5 12:45:42 cirros kern.info kernel: [ 1.419195] usb 1-1: SerialNumber: 42
Jul 5 12:45:43 cirros kern.info kernel: [ 1.750484] tsc: Refined TSC clocksource calibration: 2593.898 MHz
Jul 5 12:45:43 cirros kern.info kernel: [ 1.750488] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2563b7b6e37, max_idle_ns: 440795209024 ns
Jul 5 12:49:23 cirros authpriv.info dropbear[348]: Running in background
Jul 5 12:49:23 cirros kern.info kernel: [ 222.089354] EXT4-fs (vda1): resizing filesystem from 32768 to 1039340 blocks
############ debug end ##############
/dev/root resized successfully [took 0.21s]
____ ____ ____
/ __/ __ ____ ____ / __ \/ __/
/ /__ / // __// __// /_/ /\ \
\___//_//_/ /_/ \____/___/
http://
login as 'cirros' user. default password: 'gocubsgo'. use 'sudo' for root.
cirros login:cirros
$
$ ip a
1: lo: <LOOPBACK,
link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
inet 127.0.0.1/8 scope host lo
valid_lft forever preferred_lft forever
inet6 ::1/128 scope host
valid_lft forever preferred_lft forever
2: eth0: <BROADCAST,
link/ether fa:16:3e:18:ba:53 brd ff:ff:ff:ff:ff:ff
inet6 fe80::f816:
valid_lft forever preferred_lft forever
$
controller-0:~# openstack server list
+------
| ID | Name | Status | Networks | Image | Flavor |
+------
| cc1e49f6-
+------
controller-0:~# ping 192.168.101.218
PING 192.168.101.218 (192.168.101.218) 56(84) bytes of data.
From 192.168.200.1 icmp_seq=1 Destination Net Unreachable
From 192.168.200.1 icmp_seq=2 Destination Net Unreachable
^C
--- 192.168.101.218 ping statistics ---
2 packets transmitted, 0 received, +2 errors, 100% packet loss, time 999ms
Test Activity
-------------
[Regression Testing]
Changed in starlingx: | |
assignee: | nobody → Ricardo Pérez López (ricardo) |
assignee: | Ricardo Pérez López (ricardo) → Ricardo Perez (richomx) |
Changed in starlingx: | |
importance: | Low → Undecided |
Changed in starlingx: | |
assignee: | Forrest Zhao (forrest.zhao) → Gongjun Song (songgongjun) |
Do you see the same issue when using other cloud images - like ubuntu? Is it possible this is a guest image issue?