[Xen-devel] Question about unable to add disk device after VM is destroyed and recreated on NVIDIA Jetson board

[Meng Xu <xumengpanda@xxxxxxxxx>]

Hi all,

I'm running Xen on NVIDIA Jetson TK1 board. The Xen code is from Ian's
repo.: git://xenbits.xen.org/people/ianc/xen.git with the commit point
c78d51660446d33dac4bb07c3c17e1d14d62ebc2

Right now, I can boot dom0 on Xen on the Jetson board. After the
system boots up, I can boot up a VM1 using the vm1.config (attached
below). However, after I use "xl destroy vm1" to destroy the vm1 and
try to boot up vm1 again with the exact same configuration file, it
starts to reports the following error:

--- Start of the output of the  "xl create vm1.xl"  ---
libxl: error: libxl_device.c:952:device_backend_callback: unable to
add device with path /local/domain/0/backend/vbd/5/51712

libxl: error: libxl_create.c:1161:domcreate_launch_dm: unable to add
disk devices

libxl: error: libxl_device.c:952:device_backend_callback: unable to
remove device with path /local/domain/0/backend/vbd/5/51712

libxl: error: libxl.c:1650:devices_destroy_cb: libxl__devices_destroy
failed for 5

---End of of the output of the  "xl create vm1.xl"  ---

I found that this issue was raised before in 2013 at
http://lists.xen.org/archives/html/xen-devel/2013-02/msg00704.html
However, I didn't see the solution on that thread.

I'm wondering if someone has encountered this issue before and know
how to fix it?

Thank you very much for your help and time! Any advice is really appreciated!

I attached the configurations and more log messages as below:

---The vm1's configuration file vm1.config---

kernel = "/boot/zImage-domU" # zImage is kernel domU will uses. zImage
is inside dom0 and it’s dom0’s path.

memory = 512

name = "vm1"

vcpus = 1

disk = [ 'file:/home/ubuntu/sdcard/vm1.disk,xvda,w' ]

vif = ['bridge=xenbr0']

extra = 'console=hvc0 xencons=tty root=/dev/xvda'


--- The log message when I create vm1---

# xl -vvv create -c vm1.xl

Parsing config from vm1.xl

libxl: debug: libxl_create.c:1512:do_domain_create: ao 0x3cdd8:
create: how=(nil) callback=(nil) poller=0x3ce20

libxl: debug: libxl_device.c:269:libxl__device_disk_set_backend: Disk
vdev=xvda spec.backend=unknown

libxl: debug: libxl_device.c:298:libxl__device_disk_set_backend: Disk
vdev=xvda, using backend phy

libxl: debug: libxl_create.c:915:initiate_domain_create: running bootloader

libxl: debug: libxl_bootloader.c:329:libxl__bootloader_run: no
bootloader configured, using user supplied kernel

libxl: debug: libxl_event.c:629:libxl__ev_xswatch_deregister: watch
w=0x3d2dc: deregister unregistered

domainbuilder: detail: xc_dom_allocate: cmdline="console=hvc0
xencons=tty root=/dev/xvda", features="(null)"

libxl: debug: libxl_dom.c:536:libxl__build_pv: pv kernel mapped 0 path
/boot/zImage-domU

domainbuilder: detail: xc_dom_kernel_file: filename="/boot/zImage-domU"

domainbuilder: detail: xc_dom_malloc_filemap    : 5091 kB

domainbuilder: detail: xc_dom_boot_xen_init: ver 4.6, caps xen-3.0-armv7l

domainbuilder: detail: xc_dom_rambase_init: RAM starts at 40000

domainbuilder: detail: xc_dom_parse_image: called

domainbuilder: detail: xc_dom_find_loader: trying multiboot-binary loader ...

domainbuilder: detail: loader probe failed

domainbuilder: detail: xc_dom_find_loader: trying Linux zImage (ARM64)
loader ...

domainbuilder: detail: xc_dom_probe_zimage64_kernel: kernel is not an
arm64 Image

domainbuilder: detail: loader probe failed

domainbuilder: detail: xc_dom_find_loader: trying Linux zImage (ARM32)
loader ...

domainbuilder: detail: loader probe OK

domainbuilder: detail: xc_dom_parse_zimage32_kernel: called

domainbuilder: detail: xc_dom_parse_zimage32_kernel: xen-3.0-armv7l:
0x40008000 -> 0x40500c20

libxl: debug: libxl_arm.c:537:libxl__arch_domain_init_hw_description:
configure the domain

libxl: debug: libxl_arm.c:545:libxl__arch_domain_init_hw_description:
constructing DTB for Xen version 4.6 guest

libxl: debug: libxl_arm.c:546:libxl__arch_domain_init_hw_description:
 - vGIC version: V2

libxl: debug: libxl_arm.c:303:make_memory_nodes: Creating placeholder
node /memory@40000000

libxl: debug: libxl_arm.c:303:make_memory_nodes: Creating placeholder
node /memory@200000000

libxl: debug: libxl_arm.c:620:libxl__arch_domain_init_hw_description:
fdt total size 1266

domainbuilder: detail: xc_dom_devicetree_mem: called

domainbuilder: detail: xc_dom_mem_init: mem 512 MB, pages 0x20000 pages, 4k each

domainbuilder: detail: xc_dom_mem_init: 0x20000 pages

domainbuilder: detail: xc_dom_boot_mem_init: called

domainbuilder: detail: set_mode: guest xen-3.0-armv7l, address size 32

domainbuilder: detail: xc_dom_malloc            : 1024 kB

domainbuilder: detail: populate_guest_memory: populating RAM @
0000000040000000-0000000060000000 (512MB)

domainbuilder: detail: populate_one_size: populated 0x100/0x100
entries with shift 9

domainbuilder: detail: arch_setup_meminit: placing boot modules at 0x48000000

domainbuilder: detail: arch_setup_meminit: devicetree: 0x48000000 -> 0x48001000

libxl: debug: libxl_arm.c:651:finalise_one_memory_node: Populating
placeholder node /memory@40000000

libxl: debug: libxl_arm.c:645:finalise_one_memory_node: Nopping out
placeholder node /memory@200000000

domainbuilder: detail: xc_dom_build_image: called

domainbuilder: detail: xc_dom_alloc_segment:   kernel       :
0x40008000 -> 0x40501000  (pfn 0x40008 + 0x4f9 pages)

domainbuilder: detail: xc_dom_pfn_to_ptr_retcount: domU mapping: pfn
0x40008+0x4f9 at 0xb614c000

domainbuilder: detail: xc_dom_load_zimage_kernel: called

domainbuilder: detail: xc_dom_load_zimage_kernel: kernel seg
0x40008000-0x40501000

domainbuilder: detail: xc_dom_load_zimage_kernel: copy 5213216 bytes
from blob 0xb6746000 to dst 0xb614c000

domainbuilder: detail: xc_dom_alloc_segment:   devicetree   :
0x48000000 -> 0x48001000  (pfn 0x48000 + 0x1 pages)

domainbuilder: detail: xc_dom_pfn_to_ptr_retcount: domU mapping: pfn
0x48000+0x1 at 0xb6edc000

domainbuilder: detail: alloc_magic_pages: called

domainbuilder: detail: count_pgtables_arm: called

domainbuilder: detail: xc_dom_build_image  : virt_alloc_end : 0x48001000

domainbuilder: detail: xc_dom_build_image  : virt_pgtab_end : 0x0

domainbuilder: detail: xc_dom_boot_image: called

domainbuilder: detail: arch_setup_bootearly: doing nothing

domainbuilder: detail: xc_dom_compat_check: supported guest type:
xen-3.0-armv7l <= matches

domainbuilder: detail: setup_pgtables_arm: called

domainbuilder: detail: clear_page: pfn 0x39000, mfn 0x39000

domainbuilder: detail: clear_page: pfn 0x39001, mfn 0x39001

domainbuilder: detail: start_info_arm: called

domainbuilder: detail: domain builder memory footprint

domainbuilder: detail:    allocated

domainbuilder: detail:       malloc             : 1055 kB

domainbuilder: detail:       anon mmap          : 0 bytes

domainbuilder: detail:    mapped

domainbuilder: detail:       file mmap          : 5091 kB

domainbuilder: detail:       domU mmap          : 5096 kB

domainbuilder: detail: vcpu_arm32: called

domainbuilder: detail: Initial state CPSR 0x1d3 PC 0x40008000

domainbuilder: detail: launch_vm: called, ctxt=0xb6ef7004

domainbuilder: detail: xc_dom_gnttab_hvm_seed: called, pfn=0x38000

domainbuilder: detail: xc_dom_release: called

libxl: debug: libxl_device.c:269:libxl__device_disk_set_backend: Disk
vdev=xvda spec.backend=phy

libxl: debug: libxl_event.c:577:libxl__ev_xswatch_register: watch
w=0x3e230 wpath=/local/domain/0/backend/vbd/4/51712/state token=3/0:
register slotnum=3

libxl: debug: libxl_create.c:1528:do_domain_create: ao 0x3cdd8:
inprogress: poller=0x3ce20, flags=i

libxl: debug: libxl_event.c:514:watchfd_callback: watch w=0x3e230
wpath=/local/domain/0/backend/vbd/4/51712/state token=3/0: event
epath=/local/domain/0/backend/vbd/4/51712/state

libxl: debug: libxl_event.c:834:devstate_watch_callback: backend
/local/domain/0/backend/vbd/4/51712/state wanted state 2 still waiting
state 1

libxl: debug: libxl_event.c:848:devstate_timeout: backend
/local/domain/0/backend/vbd/4/51712/state wanted state 2  timed out

libxl: debug: libxl_event.c:615:libxl__ev_xswatch_deregister: watch
w=0x3e230 wpath=/local/domain/0/backend/vbd/4/51712/state token=3/0:
deregister slotnum=3

libxl: debug: libxl_event.c:629:libxl__ev_xswatch_deregister: watch
w=0x3e230: deregister unregistered

libxl: error: libxl_device.c:952:device_backend_callback: unable to
add device with path /local/domain/0/backend/vbd/4/51712

libxl: debug: libxl_event.c:629:libxl__ev_xswatch_deregister: watch
w=0x3e278: deregister unregistered

libxl: error: libxl_create.c:1161:domcreate_launch_dm: unable to add
disk devices

libxl: debug: libxl_event.c:577:libxl__ev_xswatch_register: watch
w=0x40358 wpath=/local/domain/0/backend/vbd/4/51712/state token=3/1:
register slotnum=3

libxl: debug: libxl_event.c:514:watchfd_callback: watch w=0x40358
wpath=/local/domain/0/backend/vbd/4/51712/state token=3/1: event
epath=/local/domain/0/backend/vbd/4/51712/state

libxl: debug: libxl_event.c:834:devstate_watch_callback: backend
/local/domain/0/backend/vbd/4/51712/state wanted state 6 still waiting
state 5

libxl: debug: libxl_event.c:848:devstate_timeout: backend
/local/domain/0/backend/vbd/4/51712/state wanted state 6  timed out

libxl: debug: libxl_event.c:615:libxl__ev_xswatch_deregister: watch
w=0x40358 wpath=/local/domain/0/backend/vbd/4/51712/state token=3/1:
deregister slotnum=3

libxl: debug: libxl_event.c:629:libxl__ev_xswatch_deregister: watch
w=0x40358: deregister unregistered

libxl: error: libxl_device.c:952:device_backend_callback: unable to
remove device with path /local/domain/0/backend/vbd/4/51712

libxl: debug: libxl_event.c:629:libxl__ev_xswatch_deregister: watch
w=0x403a0: deregister unregistered

libxl: error: libxl.c:1650:devices_destroy_cb: libxl__devices_destroy
failed for 4

libxl: debug: libxl_event.c:1766:libxl__ao_complete: ao 0x3cdd8: complete, rc=-3

libxl: debug: libxl_event.c:1738:libxl__ao__destroy: ao 0x3cdd8: destroy

xc: debug: hypercall buffer: total allocations:105 total releases:105

xc: debug: hypercall buffer: current allocations:0 maximum allocations:4

xc: debug: hypercall buffer: cache current size:4

xc: debug: hypercall buffer: cache hits:93 misses:4 toobig:8

---The xenstore information when the vm1 is created---

# xenstore-ls

local = ""

 domain = ""

  0 = ""

   domid = "0"

   name = "Domain-0"

   device-model = ""

    0 = ""

     state = "running"

   libxl = ""

    disable_udev = "1"

vm = ""

libxl = ""

root@tegra-ubuntu:~# xenstore-ls

local = ""

 domain = ""

  0 = ""

   domid = "0"

   name = "Domain-0"

   device-model = ""

    0 = ""

     state = "running"

   libxl = ""

    disable_udev = "1"

   backend = ""

    vbd = ""

     4 = ""

      51712 = ""

       frontend = "/local/domain/4/device/vbd/51712"

       params = "/home/ubuntu/sdcard/rtxen/vm1.disk"

       script = "/etc/xen/scripts/block"

       frontend-id = "4"

       online = "1"

       removable = "0"

       bootable = "1"

       state = "1"

       dev = "xvda"

       type = "phy"

       mode = "w"

       device-type = "disk"

       discard-enable = "1"

  4 = ""

   vm = "/vm/cf6806fb-c0a0-4a53-ae8d-49d67073d97a"

   name = "vm1"

   cpu = ""

    0 = ""

     availability = "online"

   memory = ""

    static-max = "524288"

    target = "524288"

    videoram = "0"

   device = ""

    suspend = ""

     event-channel = ""

    vbd = ""

     51712 = ""

      backend = "/local/domain/0/backend/vbd/4/51712"

      backend-id = "0"

      state = "1"

      virtual-device = "51712"

      device-type = "disk"

      protocol = "arm-abi"

   control = ""

    shutdown = ""

    platform-feature-multiprocessor-suspend = "1"

    platform-feature-xs_reset_watches = "1"

   data = ""

   domid = "4"

   store = ""

    port = "1"

    ring-ref = "233473"

vm = ""

 cf6806fb-c0a0-4a53-ae8d-49d67073d97a = ""

  name = "vm1"

  uuid = "cf6806fb-c0a0-4a53-ae8d-49d67073d97a"

  image = ""

   ostype = "linux"

   kernel = "/boot/zImage-domU"

   cmdline = "console=hvc0 xencons=tty root=/dev/xvda"

  start_time = "1466435399.28"

libxl = ""

 4 = ""

  dm-version = "qemu_xen"

---The xenstore information when only dom0 is running---

xenstore-ls

local = ""

 domain = ""

  0 = ""

   domid = "0"

   name = "Domain-0"

   device-model = ""

    0 = ""

     state = "running"

   libxl = ""

    disable_udev = "1"

vm = ""

libxl = ""


---Dom0's kernel has  BLKDEV frontend and backend compiled into kernel---

CONFIG_XEN_BLKDEV_FRONTEND=y

CONFIG_XEN_BLKDEV_BACKEND=y

--- Part of Dom0's dmesg ---

[   14.762403] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready

[   15.191323] ip_tables: (C) 2000-2006 Netfilter Core Team

[   15.230318] init: plymouth-upstart-bridge main process ended, respawning

[   15.274671] nf_conntrack version 0.5.0 (7948 buckets, 31792 max)

[   15.543774] init: lightdm main process (989) terminated with status 1

[   15.576962] init: plymouth-ready (startup) main process (110)
terminated with status 1

[   15.578509] init: plymouth-stop pre-start process (1138) terminated
with status 1

[   35.800498] init: failsafe-x main process (1393) terminated with status 1

[  189.420015] EXT4-fs (sdb1): mounted filesystem with ordered data
mode. Opts: (null)

[  248.338599] IPv6: ADDRCONF(NETDEV_UP): vif1.0: link is not ready

[  248.500140] device vif1.0 entered promiscuous mode

[  248.508377] IPv6: ADDRCONF(NETDEV_UP): vif1.0: link is not ready

[  249.636243] xen-blkback: ring-ref 8, event-channel 3, protocol 1
(arm-abi) persistent grants

[  249.676388] vif vif-1-0 vif1.0: Guest Rx ready

[  249.682497] IPv6: ADDRCONF(NETDEV_CHANGE): vif1.0: link becomes ready

[  249.682717] xenbr0: port 1(vif1.0) entered forwarding state

[  249.682784] xenbr0: port 1(vif1.0) entered forwarding state

[  264.727361] xenbr0: port 1(vif1.0) entered forwarding state

[  326.496191] xenbr0: port 1(vif1.0) entered disabled state

[  326.502387] xenbr0: port 1(vif1.0) entered disabled state

[  326.509849] device vif1.0 left promiscuous mode

[  326.509878] xenbr0: port 1(vif1.0) entered disabled state

[  340.651538] IPv6: ADDRCONF(NETDEV_UP): vif2.0: link is not ready

[  340.808801] device vif2.0 entered promiscuous mode

[  340.816121] IPv6: ADDRCONF(NETDEV_UP): vif2.0: link is not ready

[  341.936891] xen-blkback: ring-ref 8, event-channel 3, protocol 1
(arm-abi) persistent grants

[  341.979809] vif vif-2-0 vif2.0: Guest Rx ready

[  341.998061] IPv6: ADDRCONF(NETDEV_CHANGE): vif2.0: link becomes ready

[  341.998407] xenbr0: port 1(vif2.0) entered forwarding state

[  341.998486] xenbr0: port 1(vif2.0) entered forwarding state

[  357.047700] xenbr0: port 1(vif2.0) entered forwarding state

[  854.683579] xenbr0: port 1(vif2.0) entered disabled state

[  854.690595] xenbr0: port 1(vif2.0) entered disabled state

[  854.695034] device vif2.0 left promiscuous mode

[  854.695073] xenbr0: port 1(vif2.0) entered disabled state

[  864.909142] unregister_netdevice: waiting for vif2.0 to become
free. Usage count = 1

[  875.049099] unregister_netdevice: waiting for vif2.0 to become
free. Usage count = 1

(This "unregister_netdevice: waiting for vif2.0 to become free. Usage
count = 1" message repeats forever....)

Meng

-----------
Meng Xu
PhD Student in Computer and Information Science
University of Pennsylvania
http://www.cis.upenn.edu/~mengxu/

_______________________________________________
Xen-devel mailing list
Xen-devel@xxxxxxxxxxxxx
http://lists.xen.org/xen-devel