Custom block script started twice for root block but only stopped once

Custom block script started twice for root block but only stopped once

[Sylvain Munaut]

Hi,

I'm using a custom block script in my xen setup and when started, it
creates a new device node pointing to some network resources.

Now I noticed that the script is called twice for the root block, the
first time for pygrub most likely, but is only stopped once ... I
don't mind creating two devices node, but then I need to destroy both
...

Is this a known issue ?

 Cheers,

    Sylvain

Re: Custom block script started twice for root block but only stopped once

[Ian Campbell]

On Fri, 2012-11-02 at 10:37 +0000, Sylvain Munaut wrote:
> Hi,
> 
> I'm using a custom block script in my xen setup and when started, it
> creates a new device node pointing to some network resources.
> 
> Now I noticed that the script is called twice for the root block, the
> first time for pygrub most likely, but is only stopped once ... I
> don't mind creating two devices node, but then I need to destroy both
> ...
> 
> Is this a known issue ?

Not one I've heard. Running "xl -vvv create" might provide some logs
which give an idea what is going on, likewise the logging
in /var/log/xen/...

Roger -- any ideas?

Ian.

> 
>  Cheers,
> 
>     Sylvain
> 
> _______________________________________________
> Xen-devel mailing list
> Xen-devel@lists.xen.org
> http://lists.xen.org/xen-devel

Re: Custom block script started twice for root block but only stopped once

[Roger Pau Monné]

On 08/11/12 09:26, Ian Campbell wrote:
> On Fri, 2012-11-02 at 10:37 +0000, Sylvain Munaut wrote:
>> Hi,
>>
>> I'm using a custom block script in my xen setup and when started, it
>> creates a new device node pointing to some network resources.
>>
>> Now I noticed that the script is called twice for the root block, the
>> first time for pygrub most likely, but is only stopped once ... I
>> don't mind creating two devices node, but then I need to destroy both
>> ...
>>
>> Is this a known issue ?
> 
> Not one I've heard. Running "xl -vvv create" might provide some logs
> which give an idea what is going on, likewise the logging
> in /var/log/xen/...
> 
> Roger -- any ideas?

Yes, I've been able to reproduce the error when using stubdoms, I'm
currently working on a fix. Have you seen this when using stubdomains
Sylvain?

Also I've realized that when using stubdomains with disks that use file
based backends ("file:/") it doesn't work, is this already known, or a
regression?

Roger.

Re: Custom block script started twice for root block but only stopped once

[Ian Campbell]

On Fri, 2012-11-09 at 15:36 +0000, Roger Pau Monne wrote:
> Also I've realized that when using stubdomains with disks that use
> file based backends ("file:/") it doesn't work, is this already known,
> or a regression? 

It's news to me... I don't know if it is a regression, but it seems like
it ought to work.

Ian.

Re: Custom block script started twice for root block but only stopped once

[Roger Pau Monné]

On 09/11/12 16:36, Roger Pau Monné wrote:
> On 08/11/12 09:26, Ian Campbell wrote:
>> On Fri, 2012-11-02 at 10:37 +0000, Sylvain Munaut wrote:
>>> Hi,
>>>
>>> I'm using a custom block script in my xen setup and when started, it
>>> creates a new device node pointing to some network resources.
>>>
>>> Now I noticed that the script is called twice for the root block, the
>>> first time for pygrub most likely, but is only stopped once ... I
>>> don't mind creating two devices node, but then I need to destroy both
>>> ...
>>>
>>> Is this a known issue ?
>>
>> Not one I've heard. Running "xl -vvv create" might provide some logs
>> which give an idea what is going on, likewise the logging
>> in /var/log/xen/...
>>
>> Roger -- any ideas?
> 
> Yes, I've been able to reproduce the error when using stubdoms, I'm
> currently working on a fix. Have you seen this when using stubdomains
> Sylvain?

I've been thinking about this, and I think it's the right thing to do to
call hotplug scripts twice when using stubdomains. Each script gets
called for the corresponding PV interface of each guest. Here is a
stripped trace of the creation of a guest with a stubdomain:

[...]
libxl: debug: libxl_device.c:919:device_hotplug: for-domain: 46 - calling hotplug script: /etc/xen/scripts/block add
[...]
libxl: debug: libxl_device.c:919:device_hotplug: for-domain: 47 - calling hotplug script: /etc/xen/scripts/block add
[...]
libxl: debug: libxl_device.c:919:device_hotplug: for-domain: 47 - calling hotplug script: /etc/xen/scripts/vif-bridge online
[...]
libxl: debug: libxl_device.c:919:device_hotplug: for-domain: 46 - calling hotplug script: /etc/xen/scripts/vif-bridge online
[...]

And the destruction:

[...]
libxl: debug: libxl_device.c:919:device_hotplug: for-domain: 47 - calling hotplug script: /etc/xen/scripts/block remove
[...]
libxl: debug: libxl_device.c:919:device_hotplug: for-domain: 47 - calling hotplug script: /etc/xen/scripts/vif-bridge offline
[...]
libxl: debug: libxl_device.c:919:device_hotplug: for-domain: 46 - calling hotplug script: /etc/xen/scripts/block remove
[...]
libxl: debug: libxl_device.c:919:device_hotplug: for-domain: 46 - calling hotplug script: /etc/xen/scripts/vif-bridge offline
[...]

So hotplug script gets called twice for both creation and
destruction. Can you run a guest creation/destruction with
-vvv and provide the output?

Re: Custom block script started twice for root block but only stopped once

[Sylvain Munaut]

Hi,

Sorry for the delayed response, I didn't see anyone had answered ...
bad mail tagging rules.

For the moment I still have to use Xen 4.1.3 shipped with Debian, so
I'm still under the XM toolset and there is no -vvv AFAICT.

Cheers,

    Sylvain

Re: Custom block script started twice for root block but only stopped once

[Sylvain Munaut]

A bit more info:

I tried using PV-GRUB and this doesn't happen there, so it's only with PyGRUB.

AFAICT it happens in  tools/python/xen/xend/XendDomainInfo.py in the
_configureBootloader method.

_shouldMount will return true and so " dom0.create_vbd(vbd, disk)"
will be executed to allow access to the device to the host by
executing the block-script before the actuall booting.


[2012-11-26 13:40:44 3469] INFO (XendDomainInfo:3270) Mounting
192.168.2.201 name=rbd;key=rbd rbd-vm test on /dev/xvdp.
[2012-11-26 13:40:44 3469] DEBUG (DevController:95) DevController:
writing {'backend-id': '0', 'virtual-device': '51952', 'device-type':
'disk', 'state': '1', 'backend':
'/local/domain/0/backend/vbd/0/51952'} to
/local/domain/0/device/vbd/51952.
[2012-11-26 13:40:44 3469] DEBUG (DevController:97) DevController:
writing {'domain': 'Domain-0', 'frontend':
'/local/domain/0/device/vbd/51952', 'uuid':
'1845bb27-97b5-ce21-348d-ade6e99829e9', 'bootable': '0', 'dev':
'/dev/xvdp', 'state': '1', 'params': '192.168.2.201 name=rbd;key=rbd
rbd-vm test', 'mode': 'r', 'online': '1', 'frontend-id': '0', 'type':
'rbd'} to /local/domain/0/backend/vbd/0/51952.
[2012-11-26 13:40:44 3469] DEBUG (DevController:144) Waiting for 51952.
[2012-11-26 13:40:44 3469] DEBUG (DevController:628)
hotplugStatusCallback
/local/domain/0/backend/vbd/0/51952/hotplug-status.
[2012-11-26 13:40:45 3469] DEBUG (DevController:628)
hotplugStatusCallback
/local/domain/0/backend/vbd/0/51952/hotplug-status.
[2012-11-26 13:40:45 3469] DEBUG (DevController:642) hotplugStatusCallback 1.
[2012-11-26 13:40:45 3469] DEBUG (DevController:144) Waiting for 51952.
[2012-11-26 13:40:45 3469] DEBUG (DevController:628)
hotplugStatusCallback
/local/domain/0/backend/vbd/0/51952/hotplug-status.
[2012-11-26 13:40:45 3469] DEBUG (DevController:642) hotplugStatusCallback 1.
[2012-11-26 13:40:45 4455] DEBUG (XendBootloader:113) Launching
bootloader as ['/usr/lib/xen-4.1/bin/pygrub', '--args=console=hvc0
xencons=hvc0', '--output=/var/run/xend/boot/xenbl.7585', '-q',
'/dev/xvdp'].
[2012-11-26 13:40:48 3469] INFO (XendDomainInfo:3289) Unmounting
/dev/xvdp from /dev/xvdp.
[2012-11-26 13:40:48 3469] DEBUG (XendDomainInfo:1276)
XendDomainInfo.destroyDevice: deviceClass = vbd, device = /dev/xvdp

Now in theory the destroyDevice call should have cleared up any
resources, but it seems it didn't ...


Cheers,

    Sylvain

Re: Custom block script started twice for root block but only stopped once

[Sylvain Munaut]

Actually I managed to trace it a bit further but here I'm kind of
stuck due to my lack of knowledge of "how it should work".

Basically it does try to destruct the device and the hotplug script
'/etc/xen/scripts/block' is called with the command remove and the
right device path. However by the time it's called, the corresponding
subtree in the xenstore has been wiped it seems and so the hotplug
script fails, not knowing what to do ... and it does nothing.

So whoever triggers the hotplug remove action should leave the xen
store tree in place until the hotplug script has run.

Cheers,

    Sylvain

Re: Custom block script started twice for root block but only stopped once

[Roger Pau Monné]

On 04/12/12 16:23, Sylvain Munaut wrote:
> Actually I managed to trace it a bit further but here I'm kind of
> stuck due to my lack of knowledge of "how it should work".
> 
> Basically it does try to destruct the device and the hotplug script
> '/etc/xen/scripts/block' is called with the command remove and the
> right device path. However by the time it's called, the corresponding
> subtree in the xenstore has been wiped it seems and so the hotplug
> script fails, not knowing what to do ... and it does nothing.
> 
> So whoever triggers the hotplug remove action should leave the xen
> store tree in place until the hotplug script has run.

This is one of the reasons we no longer launch hotplug scripts from udev
in xl, it is difficult to synchronize the process, and this kind of
races can happen easily, I guess the same can happen in xend. I think
the best way to fix this would be to switch to Xen 4.2 and the xl toolstack.

Re: Custom block script started twice for root block but only stopped once

[Roger Pau Monné]

On 04/12/12 15:21, Sylvain Munaut wrote:
> A bit more info:
> 
> I tried using PV-GRUB and this doesn't happen there, so it's only with PyGRUB.
> 
> AFAICT it happens in  tools/python/xen/xend/XendDomainInfo.py in the
> _configureBootloader method.
> 
> _shouldMount will return true and so " dom0.create_vbd(vbd, disk)"
> will be executed to allow access to the device to the host by
> executing the block-script before the actuall booting.
> 
> 
> [2012-11-26 13:40:44 3469] INFO (XendDomainInfo:3270) Mounting
> 192.168.2.201 name=rbd;key=rbd rbd-vm test on /dev/xvdp.
> [2012-11-26 13:40:44 3469] DEBUG (DevController:95) DevController:
> writing {'backend-id': '0', 'virtual-device': '51952', 'device-type':
> 'disk', 'state': '1', 'backend':
> '/local/domain/0/backend/vbd/0/51952'} to
> /local/domain/0/device/vbd/51952.
> [2012-11-26 13:40:44 3469] DEBUG (DevController:97) DevController:
> writing {'domain': 'Domain-0', 'frontend':
> '/local/domain/0/device/vbd/51952', 'uuid':
> '1845bb27-97b5-ce21-348d-ade6e99829e9', 'bootable': '0', 'dev':
> '/dev/xvdp', 'state': '1', 'params': '192.168.2.201 name=rbd;key=rbd
> rbd-vm test', 'mode': 'r', 'online': '1', 'frontend-id': '0', 'type':
> 'rbd'} to /local/domain/0/backend/vbd/0/51952.
> [2012-11-26 13:40:44 3469] DEBUG (DevController:144) Waiting for 51952.
> [2012-11-26 13:40:44 3469] DEBUG (DevController:628)
> hotplugStatusCallback
> /local/domain/0/backend/vbd/0/51952/hotplug-status.
> [2012-11-26 13:40:45 3469] DEBUG (DevController:628)
> hotplugStatusCallback
> /local/domain/0/backend/vbd/0/51952/hotplug-status.
> [2012-11-26 13:40:45 3469] DEBUG (DevController:642) hotplugStatusCallback 1.
> [2012-11-26 13:40:45 3469] DEBUG (DevController:144) Waiting for 51952.
> [2012-11-26 13:40:45 3469] DEBUG (DevController:628)
> hotplugStatusCallback
> /local/domain/0/backend/vbd/0/51952/hotplug-status.
> [2012-11-26 13:40:45 3469] DEBUG (DevController:642) hotplugStatusCallback 1.
> [2012-11-26 13:40:45 4455] DEBUG (XendBootloader:113) Launching
> bootloader as ['/usr/lib/xen-4.1/bin/pygrub', '--args=console=hvc0
> xencons=hvc0', '--output=/var/run/xend/boot/xenbl.7585', '-q',
> '/dev/xvdp'].
> [2012-11-26 13:40:48 3469] INFO (XendDomainInfo:3289) Unmounting
> /dev/xvdp from /dev/xvdp.
> [2012-11-26 13:40:48 3469] DEBUG (XendDomainInfo:1276)
> XendDomainInfo.destroyDevice: deviceClass = vbd, device = /dev/xvdp
> 
> Now in theory the destroyDevice call should have cleared up any
> resources, but it seems it didn't ...

Could you give a try to xl in Xen 4.2?