[CentOS-virt] Device 0 (vif) could not be connected. Hotplug scripts not working.

Hi,

I got this error when starting a domU on Centos 5.1 i386, Device 0 (vif) could not be connected. Hotplug scripts not working.

Why is this happening ? I should restart the machine to see if this still happends after a fresh network bridge. But it's somehow a production server, I would like not to restart it, if possible. No domU is currently running. I could start domUs a week ago.

Here are the troubbleshooting information I have (everything seems fine),

- Centos 5.1 xen-3.0.3 and kernel 2.6.18-53

- ifconfig -a shows, eth0, lo, peth0, sit0, veth1, veth2, veth3, vif0.0, vif0.1, vif0.2, vid0.3 and xenbr0.

- brctl show, bridge name bridge id STP enabled interfaces xenbr0 8000.feffffffffff no peth0 vif0.0

- activated/deactivating iptables doesn't change anything. Note, securitylevel and SELinux are disabled. Currently deactivated, Chain INPUT (policy ACCEPT) target prot opt source destination

Chain FORWARD (policy ACCEPT) target prot opt source destination

Chain OUTPUT (policy ACCEPT) target prot opt source destination

- xm list -ll (domain (domid 0) (uuid 00000000-0000-0000-0000-000000000000) (vcpus 1) (cpu_weight 1.0) (memory 513) (shadow_memory 0) (maxmem 513) (features ) (name Domain-0) (on_poweroff destroy) (on_reboot restart) (on_crash restart) (state r-----) (shutdown_reason poweroff) (cpu_time 286092.966925) (online_vcpus 1) )

- loop_max is updated to 20 (which doesn't matter as I've got the vif issue, not vbd), kernel: loop: loaded (max 20 devices)

- /etc/udev/rules.d/xen-backend.rules exists, SUBSYSTEM=="xen-backend", KERNEL=="tap*", RUN+="/etc/xen/scripts/blktap $env{ACTION}" SUBSYSTEM=="xen-backend", KERNEL=="vbd*", RUN+="/etc/xen/scripts/block $env{ACTION}" SUBSYSTEM=="xen-backend", KERNEL=="vtpm*", RUN+="/etc/xen/scripts/vtpm $env{ACTION}" SUBSYSTEM=="xen-backend", KERNEL=="vif*", ACTION=="online", RUN+="$env{script} online" SUBSYSTEM=="xen-backend", KERNEL=="vif*", ACTION=="offline", RUN+="$env{script} offline" SUBSYSTEM=="xen-backend", ACTION=="remove", RUN+="/etc/xen/scripts/xen-hotplug-cleanup" KERNEL=="evtchn", NAME="xen/%k" KERNEL=="blktap[0-9]*", NAME="xen/%k"

- udev is running, root 21499 0.0 0.1 2240 624 ? S<s 15:40 0:01 /sbin/udevd -d root 22744 0.0 0.1 2044 568 pts/8 S 15:43 0:00 udevmonitor

- hald is running, 68 23539 0.0 0.6 5184 3280 ? Ss 16:23 0:00 hald root 23540 0.0 0.1 3128 952 ? S 16:23 0:00 hald-runner 68 23546 0.0 0.1 1988 776 ? S 16:23 0:00 hald-addon-keyboard: listening on /dev/input/event0

- /proc/sys/kernel/hotplug is empty (which is ok for Centos, I guess, as hald is used instead of hotplug)

- udevmonitor doesn't say anything

- /bin/sh correctly links to bash (unlike for the debian folks)

- xend.log, [2008-04-14 16:23:19 xend.XendDomainInfo 14992] DEBUG (XendDomainInfo:200) XendDomainInfo.create(['vm', ['name', 'xmb'], ['memory', '256'], ['on_reboot', 'restart'], ['on_crash', 'restart'], ['vcpus', 1], ['image', ['linux', ['kernel', '/data/xmb/vmlinuz'], ['ramdisk', '/data/xmb/initrd'], ['root', '/dev/hda1'], ['args', 'init=/bin/sh']]], ['device', ['vbd', ['uname', 'file:/data/xmb/xmb.ext3'], ['dev', 'hda1'], ['mode', 'w']]], ['device', ['vbd', ['uname', 'file:/data/xmb/xmb.swap'], ['dev', 'hda2'], ['mode', 'w']]]]) [2008-04-14 16:23:19 xend.XendDomainInfo 14992] DEBUG (XendDomainInfo:306) parseConfig: config is ['vm', ['name', 'xmb'], ['memory', '256'], ['on_reboot', 'restart'], ['on_crash', 'restart'], ['vcpus', 1], ['image', ['linux', ['kernel', '/data/xmb/vmlinuz'], ['ramdisk', '/data/xmb/initrd'], ['root', '/dev/hda1'], ['args', 'init=/bin/sh']]], ['device', ['vbd', ['uname', 'file:/data/xmb/xmb.ext3'], ['dev', 'hda1'], ['mode', 'w']]], ['device', ['vbd', ['uname', 'file:/data/xmb/xmb.swap'], ['dev', 'hda2'], ['mode', 'w']]]] [2008-04-14 16:23:19 xend.XendDomainInfo 14992] DEBUG (XendDomainInfo:411) parseConfig: result is {'shadow_memory': None, 'start_time': None, 'uuid': None, 'on_crash': 'restart', 'on_reboot': 'restart', 'localtime': None, 'image': ['linux', ['kernel', '/data/xmb/vmlinuz'], ['ramdisk', '/data/xmb/initrd'], ['root', '/dev/hda1'], ['args', 'init=/bin/sh']], 'on_poweroff': None, 'bootloader_args': None, 'cpus': None, 'name': 'xmb', 'backend': [], 'vcpus': 1, 'cpu_weight': None, 'features': None, 'vcpu_avail': None, 'memory': 256, 'device': [('vbd', ['vbd', ['uname', 'file:/data/xmb/xmb.ext3'], ['dev', 'hda1'], ['mode', 'w']]), ('vbd', ['vbd', ['uname', 'file:/data/xmb/xmb.swap'], ['dev', 'hda2'], ['mode', 'w']])], 'bootloader': None, 'cpu': None, 'maxmem': None} [2008-04-14 16:23:19 xend.XendDomainInfo 14992] DEBUG (XendDomainInfo:1349) XendDomainInfo.construct: None [2008-04-14 16:23:19 xend 14992] DEBUG (balloon:127) Balloon: 487248 KiB free; need 2048; done. [2008-04-14 16:23:19 xend.XendDomainInfo 14992] DEBUG (XendDomainInfo:1397) XendDomainInfo.initDomain: 51 1.0 [2008-04-14 16:23:19 xend.XendDomainInfo 14992] DEBUG (XendDomainInfo:1436) _initDomain:shadow_memory=0x0, maxmem=0x100, memory=0x100. [2008-04-14 16:23:19 xend 14992] DEBUG (balloon:127) Balloon: 487248 KiB free; need 262144; done. [2008-04-14 16:23:19 xend 14992] INFO (image:136) buildDomain os=linux dom=51 vcpus=1 [2008-04-14 16:23:19 xend 14992] DEBUG (image:201) domid = 51 [2008-04-14 16:23:19 xend 14992] DEBUG (image:202) memsize = 256 [2008-04-14 16:23:19 xend 14992] DEBUG (image:203) image = /data/xmb/vmlinuz [2008-04-14 16:23:19 xend 14992] DEBUG (image:204) store_evtchn = 1 [2008-04-14 16:23:19 xend 14992] DEBUG (image:205) console_evtchn = 2 [2008-04-14 16:23:19 xend 14992] DEBUG (image:206) cmdline = root=/dev/hda1 init=/bin/sh [2008-04-14 16:23:19 xend 14992] DEBUG (image:207) ramdisk = /data/xmb/initrd [2008-04-14 16:23:19 xend 14992] DEBUG (image:208) vcpus = 1 [2008-04-14 16:23:19 xend 14992] DEBUG (image:209) features = [2008-04-14 16:23:20 xend 14992] DEBUG (blkif:24) exception looking up device number for hda1: [Errno 2] No such file or directory: '/dev/hda1' [2008-04-14 16:23:20 xend 14992] DEBUG (DevController:110) DevController: writing {'virtual-device': '769', 'device-type': 'disk', 'protocol': 'x86_32-abi', 'backend-id': '0', 'state': '1', 'backend': '/local/domain/0/backend/vbd/51/769'} to /local/domain/51/device/vbd/769. [2008-04-14 16:23:20 xend 14992] DEBUG (DevController:112) DevController: writing {'domain': 'xmb', 'frontend': '/local/domain/51/device/vbd/769', 'dev': 'hda1', 'state': '1', 'params': '/data/xmb/xmb.ext3', 'mode': 'w', 'online': '1', 'frontend-id': '51', 'type': 'file'} to /local/domain/0/backend/vbd/51/769. [2008-04-14 16:23:20 xend 14992] DEBUG (blkif:24) exception looking up device number for hda2: [Errno 2] No such file or directory: '/dev/hda2' [2008-04-14 16:23:20 xend 14992] DEBUG (DevController:110) DevController: writing {'virtual-device': '770', 'device-type': 'disk', 'protocol': 'x86_32-abi', 'backend-id': '0', 'state': '1', 'backend': '/local/domain/0/backend/vbd/51/770'} to /local/domain/51/device/vbd/770. [2008-04-14 16:23:20 xend 14992] DEBUG (DevController:112) DevController: writing {'domain': 'xmb', 'frontend': '/local/domain/51/device/vbd/770', 'dev': 'hda2', 'state': '1', 'params': '/data/xmb/xmb.swap', 'mode': 'w', 'online': '1', 'frontend-id': '51', 'type': 'file'} to /local/domain/0/backend/vbd/51/770. [2008-04-14 16:23:20 xend.XendDomainInfo 14992] DEBUG (XendDomainInfo:756) Storing VM details: {'shadow_memory': '0', 'uuid': '196487de-140f-ef22-4b77-131313b013e8', 'on_reboot': 'restart', 'start_time': '1208183000.15', 'on_poweroff': 'destroy', 'name': 'xmb', 'xend/restart_count': '0', 'vcpus': '1', 'vcpu_avail': '1', 'memory': '256', 'on_crash': 'restart', 'image': "(linux (kernel /data/xmb/vmlinuz) (ramdisk /data/xmb/initrd) (root /dev/hda1) (args 'init=/bin/sh'))", 'maxmem': '256'} [2008-04-14 16:23:20 xend.XendDomainInfo 14992] DEBUG (XendDomainInfo:791) Storing domain details: {'console/ring-ref': '145356', 'console/port': '2', 'name': 'xmb', 'console/limit': '1048576', 'vm': '/vm/196487de-140f-ef22-4b77-131313b013e8', 'domid': '51', 'cpu/0/availability': 'online', 'memory/target': '262144', 'store/ring-ref': '145357', 'store/port': '1'} [2008-04-14 16:23:20 xend.XendDomainInfo 14992] DEBUG (XendDomainInfo:988) XendDomainInfo.handleShutdownWatch [2008-04-14 16:23:20 xend 14992] DEBUG (DevController:143) Waiting for devices vif. [2008-04-14 16:23:20 xend 14992] DEBUG (DevController:143) Waiting for devices usb. [2008-04-14 16:23:20 xend 14992] DEBUG (DevController:143) Waiting for devices vbd. [2008-04-14 16:23:20 xend 14992] DEBUG (DevController:149) Waiting for 769. [2008-04-14 16:23:20 xend 14992] DEBUG (DevController:476) hotplugStatusCallback /local/domain/0/backend/vbd/51/769/hotplug-status. [2008-04-14 16:25:00 xend.XendDomainInfo 14992] DEBUG (XendDomainInfo:1557) XendDomainInfo.destroy: domid=51 [2008-04-14 16:25:00 xend.XendDomainInfo 14992] DEBUG (XendDomainInfo:1566) XendDomainInfo.destroyDomain(51)

Note, someone reported the bug on RHEL5 x86_64; I guess I shouldn't add a command as a CentOS user (not mentioning I doubt I could reproduce the bug), https://bugzilla.redhat.com/show_bug.cgi?id=408901

Anthing I could do to dig some more ? How to fix this ? I can't play around so much on this server, although I already restarted udev and haldaemon, no changes. (I might reboot it some day but the problem may disapear then, after a fresh reboot).

Thanks