Re: [Xen-users] xen_blkbk times out before getting connected

[Yathindra <ydev@xxxxxxxxxxx>]

On 2/8/2013 4:32 PM, Yathindra wrote:
> On 2/5/2013 7:45 PM, Yathindra wrote:
> > On 2/5/2013 11:11 AM, Roger Pau Monné wrote:
> > > On 05/02/13 18:11, Yathindra wrote:
> > > > DomU configuration file looks like this:
> > > Please don't do top posting.
> > >
> > > > kernel = "/boot/vmlinuz-3.8.0-rc5+"
> > > > ramdisk = "/boot/initrd.img-3.8.0-rc5+"
> > > > memory = 500
> > > > name = "guest2"
> > > > disk = ['phy:/dev/loop0,sda1,w']
> > > Why are you using sda1 instead of xvda1?
> > >
> > > > root = "/dev/disk/by-path/xen-vbd-2049 ro"
> > > > extra = 'xencons=tty'
> > > You can use:
> > >
> > > extra="root=/dev/xvda1"
> > >
> > > > On 2/5/2013 2:59 AM, Roger Pau Monné wrote:
> > > > > On 03/02/13 18:50, Yathindra wrote:
> > > > > > I'm using the latest linux kernel 3.8.0 with Xen 4.3-unstable. 
> > > > > > Xenstored
> > > > > > is being started at boot time.
> > > > > > I did not see any message (dmesg/syslog/console) about device being
> > > > > > plugged in but xenstore-ls shows me all
> > > > > > the entries backend and frontend.
> > > > > Could you post your DomU configuration file also?
> > > > >
> > > > > > Here are some details
> > > > > > ------------------------------
> > > > > >    From /var/log/syslog:
> > > > > >
> > > > > > Feb  3 10:37:31 localhost kernel: [   36.466359] Event-channel 
> > > > > > device
> > > > > > installed.
> > > > > > Feb  3 10:37:31 localhost kernel: [   36.636358] Register
> > > > > > xen_blkbk_driver  <<< custom debug message I added
> > > > > > Feb  3 10:37:31 localhost kernel: [   36.636367]
> > > > > > xenbus_register_backend   <<< custom debug message I added
> > > > > > Feb  3 10:37:31 localhost kernel: [   36.683533] 
> > > > > > xenbus_register_backend
> > > > > > Feb  3 10:37:31 localhost kernel: [   36.830115] xen-pciback: 
> > > > > > backend is
> > > > > > vpci  <<< custom debug message I added
> > > > > > Feb  3 10:37:31 localhost kernel: [   36.830123]
> > > > > > xenbus_register_backend       <<< custom debug message I added
> > > > > > Feb  3 10:37:32 localhost xenstored: Checking store ...
> > > > > > Feb  3 10:37:32 localhost xenstored: Checking store complete.
> > > > > > Feb  3 10:37:32 localhost kernel: [   37.075217] xenbus_probe: 
> > > > > > xenstored
> > > > > > is ready  <<< custom debug message I added
> > > > > > Feb  3 10:37:32 localhost kernel: [   37.075230] watching node
> > > > > > FFFFFFFF81C7D1A0
> > > > > > Feb  3 10:37:32 localhost kernel: [   37.081309] xenbus_scanf for 
> > > > > > node cpu/0
> > > > > > Feb  3 10:37:32 localhost kernel: [   37.081327] XENBUS xen store 
> > > > > > gave:
> > > > > > unknown error cpu
> > > > > > Feb  3 10:37:32 localhost kernel: [   37.081333] xenbus_scanf for 
> > > > > > node cpu/1
> > > > > > Feb  3 10:37:32 localhost kernel: [   37.085327] XENBUS 
> > > > > > unexpected type
> > > > > > [17], expected [2]
> > > > > > Feb  3 10:37:32 localhost kernel: [   37.085342] watching node
> > > > > > FFFFFFFF81C7D0C0
> > > > > > Feb  3 10:37:32 localhost kernel: [   37.086857] XENBUS 
> > > > > > unexpected type
> > > > > > [17], expected [4]
> > > > > > Feb  3 10:37:32 localhost kernel: [   37.086865] Failed to set 
> > > > > > shutdown
> > > > > > watcher
> > > > > > Feb  3 10:37:32 localhost kernel: [   37.086880] 
> > > > > > backend_probe_and_watch
> > > > > > - enumerates devices in xenstore and watches for changes <<< custom
> > > > > > debug message I added
> > > > > > Feb  3 10:37:32 localhost kernel: [   37.089401] XENBUS 
> > > > > > unexpected type
> > > > > > [4], expected [1]
> > > > > > Feb  3 10:37:32 localhost kernel: [   37.089411] watching node
> > > > > > FFFFFFFF81C7D660
> > > > > > Feb  3 10:37:32 localhost kernel: [   37.090715] XENBUS xen store 
> > > > > > gave:
> > > > > > unknown error control/shutdown
> > > > > > Feb  3 10:37:32 localhost kernel: [   37.090725]
> > > > > > frontend_probe_and_watch: calling xenbus_probe_devices <<< custom 
> > > > > > debug
> > > > > > message I added
> > > > > > Feb  3 10:37:32 localhost kernel: [   37.092362] XENBUS 
> > > > > > unexpected type
> > > > > > [17], expected [1]
> > > > > > Feb  3 10:37:32 localhost kernel: [   37.092376] watching node
> > > > > > FFFFFFFF81C7D820
> > > > > > Feb  3 10:37:32 localhost kernel: [   37.093334] watching node
> > > > > > FFFFFFFF81C7DB20
> > > > > > Feb  3 10:37:32 localhost kernel: [   37.094454] XENBUS xen store 
> > > > > > gave:
> > > > > > unknown error backend   <<< still not sure how critical this is
> > > > > > Feb  3 10:37:32 localhost kernel: [   37.094463] Failed to set 
> > > > > > balloon
> > > > > > watcher                                    <<< still not sure how
> > > > > > critical this is
> > > > > >
> > > > > >    > xenstore-ls
> > > > > > tool = ""
> > > > > >     xenstored = ""
> > > > > > local = ""
> > > > > >     domain = ""
> > > > > >      0 = ""
> > > > > >       data = ""
> > > > > >        meminfo_total = "930680"
> > > > > >        meminfo_free = "691868"
> > > > > >        os_name = "Ubuntu 12.04.1 LTS"
> > > > > >        os_majorver = "12"
> > > > > >        os_minorver = "04"
> > > > > >        os_uname = "3.8.0-rc5+"
> > > > > >        os_distro = "ubuntu"
> > > > > >        updated = "Sun Feb  3 10:43:32 MST 2013"
> > > > > >       name = "Domain-0"
> > > > > >       attr = ""
> > > > > >        xenbr0 = ""
> > > > > >         ip = "155.98.39.2"
> > > > > >        PVAddons = ""
> > > > > >         MajorVersion = "5"
> > > > > >         MinorVersion = "5"
> > > > > >         MicroVersion = "0"
> > > > > >         BuildVersion = "17913"
> > > > > >         Installed = "1"
> > > > > >       device-model = ""
> > > > > >        0 = ""
> > > > > >         state = "running"
> > > > > >
> > > > > > After this I start the guest domain, here's the xenstore entries,
> > > > > >
> > > > > > nodea:~> sudo xenstore-ls
> > > > > > tool = ""
> > > > > >     xenstored = ""
> > > > > > local = ""
> > > > > >     domain = ""
> > > > > >      0 = ""
> > > > > >       data = ""
> > > > > >        meminfo_total = "930680"
> > > > > >        meminfo_free = "695408"
> > > > > >        os_name = "Ubuntu 12.04.1 LTS"
> > > > > >        os_majorver = "12"
> > > > > >        os_minorver = "04"
> > > > > >        os_uname = "3.8.0-rc5+"
> > > > > >        os_distro = "ubuntu"
> > > > > >        updated = "Sun Feb  3 10:45:32 MST 2013"
> > > > > >       name = "Domain-0"
> > > > > >       attr = ""
> > > > > >        xenbr0 = ""
> > > > > >         ip = "155.98.39.2"
> > > > > >        PVAddons = ""
> > > > > >         MajorVersion = "5"
> > > > > >         MinorVersion = "5"
> > > > > >         MicroVersion = "0"
> > > > > >         BuildVersion = "17913"
> > > > > >         Installed = "1"
> > > > > >       device-model = ""
> > > > > >        0 = ""
> > > > > >         state = "running"
> > > > > >       memory = ""
> > > > > >        target = "1048576"
> > > > > >        static-max = "4294967292"
> > > > > >        freemem-slack = "314476"
> > > > > >       libxl = ""
> > > > > >        disable_udev = "1"
> > > > > >       backend = ""
> > > > > >        vbd = ""
> > > > > >         1 = ""
> > > > > >          2049 = ""
> > > > > >           frontend = "/local/domain/1/device/vbd/2049" <<<< 
> > > > > > everything
> > > > > > seems to be enumerated
> > > > > >           params = "/dev/loop0"
> > > > > >           script = "/etc/xen/scripts/block"
> > > > > >           physical-device = "7:0"
> > > > > >           frontend-id = "1"
> > > > > >           online = "1"
> > > > > >           removable = "0"
> > > > > >           bootable = "1"
> > > > > >           state = "1"
> > > > > >           dev = "sda1"
> > > > > >           type = "phy"
> > > > > >           mode = "w"
> > > > > >           device-type = "disk"
> > > > > >      1 = ""
> > > > > >       vm = "/vm/9b0dfb10-f69d-4e22-9158-bb70456ece2e"
> > > > > >       name = "guest2"
> > > > > >       cpu = ""
> > > > > >        0 = ""
> > > > > >         availability = "online"
> > > > > >       memory = ""
> > > > > >        static-max = "512000"
> > > > > >        target = "512001"
> > > > > >        videoram = "-1"
> > > > > >       device = ""
> > > > > >        suspend = ""
> > > > > >         event-channel = ""
> > > > > >        vbd = ""
> > > > > >         2049 = ""
> > > > > >          backend = "/local/domain/0/backend/vbd/1/2049"
> > > > > >          backend-id = "0"
> > > > > >          state = "1" <<<<< state changes to 5 and then after 5 
> > > > > > secs it
> > > > > > times out
> > > > > >          virtual-device = "2049"
> > > > > >          device-type = "disk"
> > > > > >       control = ""
> > > > > >        shutdown = ""
> > > > > >        platform-feature-multiprocessor-suspend = "1"
> > > > > >        platform-feature-xs_reset_watches = "1"
> > > > > >       data = ""
> > > > > >       domid = "1"
> > > > > >       store = ""
> > > > > >        port = "1"
> > > > > >        ring-ref = "156845"
> > > > > > vm = ""
> > > > > >     9b0dfb10-f69d-4e22-9158-bb70456ece2e = ""
> > > > > >      uuid = "9b0dfb10-f69d-4e22-9158-bb70456ece2e"
> > > > > >      name = "guest2"
> > > > > >      image = ""
> > > > > >       ostype = "linux"
> > > > > >       kernel = "/boot/vmlinuz-3.8.0-rc5+"
> > > > > >       ramdisk = "/boot/initrd.img-3.8.0-rc5+"
> > > > > >       cmdline = "root=/dev/disk/by-path/xen-vbd-2049 ro xencons=tty"
> > > > > >      start_time = "1359913591.67"
> > > > > > libxl = ""
> > > > > >     1 = ""
> > > > > >      dm-version = "qemu_xen"
> > > > > >
> > > > > > Thanks,
> > > > > > Yathi
> > Sorry about top posting. I changed it to xvda1 and I still see the 
> > same behavior.
> I instrumented the backend drivers and here's a trace of the events. I 
> observed that
> XS_DIRECTORY for "backend" ( as the "backend" node was not created in 
> xenstore yet)
> and "device" ( as the "device" node was not created in xenstore yet) 
> fails to return anything.
> Are they supposed to be in xenstore right after dom0 is created ?
>
> [    3.011816] xen-balloon: Initialising balloon driver.
> [    3.016043] xen/balloon: Xen selfballooning driver disabled for 
> domain0.
> [    3.420054] Switching to clocksource xen
> [    3.510038] xen: registering gsi 13 triggering 1 polarity 0
> [    3.540022] xen: registering gsi 8 triggering 1 polarity 0
> [    3.566198] xen: registering gsi 4 triggering 1 polarity 0
> [    3.589252] xen: registering gsi 3 triggering 1 polarity 0
> [    4.096790] xen: registering gsi 16 triggering 0 polarity 1
> [    4.102431] xen: --> pirq=16 -> irq=16 (gsi=16)
> [    4.107062] xen: registering gsi 16 triggering 0 polarity 1
> [    4.116460] xen: registering gsi 16 triggering 0 polarity 1
> [    4.125956] xen: registering gsi 16 triggering 0 polarity 1
> [    4.135307] xen: registering gsi 16 triggering 0 polarity 1
> [    4.144529] xen: registering gsi 16 triggering 0 polarity 1
> [    4.153912] xen: registering gsi 16 triggering 0 polarity 1
> [    4.163262] xen: registering gsi 16 triggering 0 polarity 1
> [    4.469657] xen: registering gsi 21 triggering 0 polarity 1
> [    4.475307] xen: --> pirq=21 -> irq=21 (gsi=21)
> [    4.486553] xen: registering gsi 20 triggering 0 polarity 1
> [    4.492186] xen: --> pirq=20 -> irq=20 (gsi=20)
> [    4.503457] xen: registering gsi 21 triggering 0 polarity 1
> [    4.519484] xen: registering gsi 20 triggering 0 polarity 1
> [    4.535518] xen: registering gsi 21 triggering 0 polarity 1
> [    5.733514] xenbus_register_frontend
> [    5.788723] xenbus_register_frontend
> [    5.796982] xen: registering gsi 23 triggering 0 polarity 1
> [    5.802619] xen: --> pirq=23 -> irq=23 (gsi=23)
> [    6.019447] xenbus_register_frontend
> [    6.029696] xen: registering gsi 21 triggering 0 polarity 1
> [    6.122280] xen: registering gsi 21 triggering 0 polarity 1
> [    6.214955] xen: registering gsi 20 triggering 0 polarity 1
> [    6.262081] xen: registering gsi 21 triggering 0 polarity 1
> [    6.309240] xen: registering gsi 20 triggering 0 polarity 1
> [    6.657173] xen: registering gsi 18 triggering 0 polarity 1
> [    6.657232] xen: registering gsi 16 triggering 0 polarity 1
> [    6.672277] xen: --> pirq=18 -> irq=18 (gsi=18)
> [    6.761063] xen: registering gsi 16 triggering 0 polarity 1
> [    6.785518] xen: registering gsi 16 triggering 0 polarity 1
> [    7.015253] xen: registering gsi 19 triggering 0 polarity 1
> [    7.020861] xen: --> pirq=19 -> irq=19 (gsi=19)
> [    7.339228] xen: registering gsi 16 triggering 0 polarity 1
> [    7.673945] xen: registering gsi 17 triggering 0 polarity 1
> [    7.679568] xen: --> pirq=17 -> irq=17 (gsi=17)
> [   38.374483] xen: registering gsi 19 triggering 0 polarity 1
> [   44.712442] xenbr0: port 1(eth0) entered forwarding state
> [   44.712449] xenbr0: port 1(eth0) entered forwarding state
> [   48.572924] xen_blkif_xenbus_init: Register xen_blkbk_driver
> [   48.572928] xenbus_register_backend
> [   48.596414] xenbus_register_backend
> [   48.619245] xen-pciback: backend is vpci
> [   48.619251] xenbus_register_backend
> [   48.776436] xenbus_scanf for node cpu/0
> [   48.782133] XENBUS xen store gave: unknown error cpu
> [   48.782137] xenbus_scanf for node cpu/1
> [   48.782386] xenbus_scanf for node cpu/2
> [   48.782605] xenbus_scanf for node cpu/3
> [   48.782813] xenbus_scanf for node cpu/4
> [   48.783019] xenbus_scanf for node cpu/5
> [   48.783225] xenbus_scanf for node cpu/6
> [   48.783432] xenbus_scanf for node cpu/7
> [   48.783917] Failed to set shutdown watcher
> ======================================================================================================== 
>
> [   48.793731] backend_probe_and_watch
> [   48.793733] xenbus_probe_devices started ...
> [   48.793821] xenbus_directory: get dir "backend" contents
> [   48.793825] xenbus_directory: ERROR getting dir 
> 8\xffffff92\xffffffb9\xfffffff7\x01\xffffff88\xffffffff\xffffffff\xffff
> ffd0\xffffff99\xffffff99\xffffffb9\xfffffff7\x01\xffffff88\xffffffff\xffffffffX\xffffff92\xffffffb9\xfffffff7\x01\xffffff8 
>
> 8\xffffffff\xffffffff`\xffffff92\xffffffb9\xfffffff7\x01\xffffff88\xffffffff\xffffffff\xffffff98\xffffff90\xffffffb9\xffff 
>
> fff7\x01\xffffff88\xffffffff\xffffffff\xffffffc8\xffffff99\xffffff99\xffffffb9\xfffffff7\x01\xffffff88\xffffffff\xffffffff 
>
> \x01 contents
> [   48.793827] xenbus_probe_devices: ERROR after xenbus_directory
> [   48.793831] XENBUS xen store gave: unknown error control/shutdown
> [   48.793831] XENBUS xen store gave: unknown error control/shutdown
> ======================================================================================================== 
>
> [   48.793833] frontend_probe_and_watch
> [   48.793835] xenbus_probe_devices started ...
> [   48.793837] xenbus_directory: get dir "device" contents
> [   48.797288] xenbus_directory: ERROR getting dir 
> 8\xffffff92\xffffffb9\xfffffff7\x01\xffffff88\xffffffff\xffffffffOK cos
> [   48.797290] xenbus_probe_devices: ERROR after xenbus_directory
> [   48.797298] XENBUS xen store gave: unknown error backend
> [   48.797299] Failed to set balloon watcher
> ======================================================================================================== 
>
> [   59.740081] xenbr0: port 1(eth0) entered forwarding state
> [   63.739432] NFS: Registering the id_resolver key type
> [   63.739455] Key type id_resolver registered
> [   63.739457] Key type id_legacy registered
> [   82.767858] init: ttyS0 main process (2257) terminated with status 1
> [   82.767909] init: ttyS0 main process ended, respawning
>
> Thanks,
> Yathi
The trace was right after dom0 was running. I did not create any guest 
domain yet.
Once I create the guest domain, I do not see any more messages from 
backend/frontend.
Is it because xenbus_probe_devices is called only once from 
xenbus_probe_backend_init ?
If thats the case, when guest starts xenbus_probe_devices is not called 
to connect the
disk ?

Thanks,
Yathi


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