Xen project Mailing List

[2013-03-13 13:03:05 1983] DEBUG (XendDomainInfo:3077) XendDomainInfo.destroy: domid=3

[2013-03-13 13:03:05 1983] DEBUG (XendDomainInfo:1882) XendDomainInfo.handleShutdownWatch

[2013-03-13 13:03:05 1983] DEBUG (XendDomainInfo:2402) Destroying device model

[2013-03-13 13:03:05 1983] DEBUG (XendDomainInfo:2409) Releasing devices

[2013-03-13 13:03:05 1983] DEBUG (XendDomainInfo:2415) Removing vif/0

[2013-03-13 13:03:05 1983] DEBUG (XendDomainInfo:1276) XendDomainInfo.destroyDevice: deviceClass = vif, device = vif/0

[2013-03-13 13:03:05 1983] DEBUG (XendDomainInfo:2415) Removing console/0

[2013-03-13 13:03:05 1983] DEBUG (XendDomainInfo:1276) XendDomainInfo.destroyDevice: deviceClass = console, device = c$

[2013-03-13 13:03:05 1983] DEBUG (XendDomainInfo:2415) Removing vbd/51712

[2013-03-13 13:03:05 1983] DEBUG (XendDomainInfo:1276) XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/5$

[2013-03-13 13:03:06 1983] DEBUG (XendDomainInfo:2407) No device model

[2013-03-13 13:03:06 1983] DEBUG (XendDomainInfo:2409) Releasing devices

[2013-03-13 13:03:06 1983] DEBUG (XendDomainInfo:2415) Removing vif/0

[2013-03-13 13:03:06 1983] DEBUG (XendDomainInfo:1276) XendDomainInfo.destroyDevice: deviceClass = vif, device = vif/0

[2013-03-13 13:03:06 1983] DEBUG (XendDomainInfo:2415) Removing vbd/51712

[2013-03-13 13:03:06 1983] DEBUG (XendDomainInfo:1276) XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/5$

[2013-03-13 13:04:46 1983] DEBUG (XendDomainInfo:103) XendDomainInfo.create(['vm', ['name', 'Sb-Voip1-DomU'], ['memory$

[2013-03-13 13:03:06 1983] DEBUG (XendDomainInfo:1276) XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/5$

[2013-03-13 13:04:46 1983] DEBUG (XendDomainInfo:103) XendDomainInfo.create(['vm', ['name', 'Sb-Voip1-DomU'], ['memory$

[2013-03-13 13:04:46 1983] DEBUG (XendDomainInfo:2499) XendDomainInfo.constructDomain

[2013-03-13 13:04:46 1983] DEBUG (balloon:187) Balloon: 2058876 KiB free; need 16384; done.

[2013-03-13 13:04:47 1983] DEBUG (XendDomain:476) Adding Domain: 4

[2013-03-13 13:04:47 1983] DEBUG (XendDomainInfo:2842) XendDomainInfo.initDomain: 4 256

[2013-03-13 13:04:47 1983] INFO (XendDomainInfo:3276) Mounting drbd-vm on /dev/xvdp.

[2013-03-13 13:04:47 1983] DEBUG (DevController:95) DevController: writing {'backend-id': '0', 'virtual-device': '5195$

[2013-03-13 13:04:47 1983] DEBUG (DevController:97) DevController: writing {'domain': 'Domain-0', 'frontend': '/local/$

[2013-03-13 13:04:47 1983] DEBUG (DevController:144) Waiting for 51952.

[2013-03-13 13:04:47 1983] DEBUG (DevController:628) hotplugStatusCallback /local/domain/0/backend/vbd/0/51952/hotplug$

[2013-03-13 13:04:47 1983] DEBUG (DevController:642) hotplugStatusCallback 1.

[2013-03-13 13:04:47 1983] DEBUG (DevController:144) Waiting for 51952.

[2013-03-13 13:04:47 1983] DEBUG (DevController:628) hotplugStatusCallback /local/domain/0/backend/vbd/0/51952/hotplug$

[2013-03-13 13:04:47 1983] DEBUG (DevController:642) hotplugStatusCallback 1.

[2013-03-13 13:04:47 4725] DEBUG (XendBootloader:113) Launching bootloader as ['/usr/bin/pygrub', '--output=/var/run/x$

[2013-03-13 13:04:49 1983] INFO (XendDomainInfo:3295) Unmounting /dev/xvdp from /dev/xvdp.

[2013-03-13 13:04:49 1983] DEBUG (XendDomainInfo:1276) XendDomainInfo.destroyDevice: deviceClass = vbd, device = /dev/$

[2013-03-13 13:04:49 1983] DEBUG (XendDomainInfo:2869) _initDomain:shadow_memory=0x0, memory_static_max=0x40000000, me$

[2013-03-13 13:04:49 1983] INFO (image:182) buildDomain os=linux dom=4 vcpus=1

[2013-03-13 13:04:49 1983] DEBUG (image:721) domid = 4

[2013-03-13 13:04:49 1983] DEBUG (image:722) memsize = 1024

[2013-03-13 13:04:49 1983] DEBUG (image:723) image = /var/run/xend/boot/boot_kernel.bWctVs

[2013-03-13 13:04:49 1983] DEBUG (image:724) store_evtchn = 1

[2013-03-13 13:04:49 1983] DEBUG (image:723) image = /var/run/xend/boot/boot_kernel.bWctVs

[2013-03-13 13:04:49 1983] DEBUG (image:724) store_evtchn = 1

[2013-03-13 13:04:49 1983] DEBUG (image:725) console_evtchn = 2

[2013-03-13 13:04:49 1983] DEBUG (image:726) cmdline = root=UUID=f76e1730-ef98-43f3-ae37-caaff1dbe5c1 ro consol$

[2013-03-13 13:04:49 1983] DEBUG (image:727) ramdisk = /var/run/xend/boot/boot_ramdisk.GF_u4x

[2013-03-13 13:04:49 1983] DEBUG (image:728) vcpus = 1

[2013-03-13 13:04:49 1983] DEBUG (image:729) features =

[2013-03-13 13:04:49 1983] DEBUG (image:730) flags = 0

[2013-03-13 13:04:49 1983] DEBUG (image:731) superpages = 0

[2013-03-13 13:04:50 1983] INFO (XendDomainInfo:2358) createDevice: vbd : {'uuid': '2601a8a4-f53c-e392-44b7-4d79ecb6bf$

[2013-03-13 13:04:50 1983] DEBUG (DevController:95) DevController: writing {'virtual-device': '51712', 'device-type': $

[2013-03-13 13:04:50 1983] DEBUG (DevController:97) DevController: writing {'domain': 'Sb-Voip1-DomU', 'frontend': '/l$

[2013-03-13 13:04:50 1983] INFO (XendDomainInfo:2358) createDevice: vif : {'ip': '192.168.129.55', 'mac': '00:16:3e:35$

[2013-03-13 13:04:50 1983] DEBUG (DevController:95) DevController: writing {'mac': '00:16:3e:35:82:be', 'handle': '0',$

[2013-03-13 13:04:50 1983] DEBUG (DevController:97) DevController: writing {'bridge': 'xenbr0', 'domain': 'Sb-Voip1-Do$

[2013-03-13 13:04:50 1983] DEBUG (XendDomainInfo:3426) Storing VM details: {'on_xend_stop': 'ignore', 'pool_name': 'Po$

[2013-03-13 13:04:50 1983] DEBUG (XendDomainInfo:1795) Storing domain details: {'console/ring-ref': '270105', 'image/e$

[2013-03-13 13:04:50 1983] DEBUG (DevController:95) DevController: writing {'protocol': 'x86_64-abi', 'state': '1', 'b$

[2013-03-13 13:04:50 1983] DEBUG (DevController:97) DevController: writing {'domain': 'Sb-Voip1-DomU', 'frontend': '/l$

[2013-03-13 13:04:51 1983] DEBUG (XendDomainInfo:1882) XendDomainInfo.handleShutdownWatch

[2013-03-13 13:04:51 1983] DEBUG (DevController:139) Waiting for devices tap2.

[2013-03-13 13:04:51 1983] DEBUG (DevController:139) Waiting for devices vif.

[2013-03-13 13:04:51 1983] DEBUG (DevController:144) Waiting for 0.

[2013-03-13 13:04:51 1983] DEBUG (DevController:628) hotplugStatusCallback /local/domain/0/backend/vif/4/0/hotplug-sta$

[2013-03-13 13:04:51 1983] DEBUG (DevController:642) hotplugStatusCallback 1.

[2013-03-13 13:04:51 1983] DEBUG (DevController:139) Waiting for devices vkbd.

[2013-03-13 13:04:51 1983] DEBUG (DevController:139) Waiting for devices ioports.

[2013-03-13 13:04:51 1983] DEBUG (DevController:139) Waiting for devices tap.

[2013-03-13 13:04:51 1983] DEBUG (DevController:139) Waiting for devices vif2.

[2013-03-13 13:04:51 1983] DEBUG (DevController:139) Waiting for devices console.

[2013-03-13 13:04:51 1983] DEBUG (DevController:144) Waiting for 0.

[2013-03-13 13:04:51 1983] DEBUG (DevController:139) Waiting for devices vscsi.

[2013-03-13 13:04:51 1983] DEBUG (DevController:139) Waiting for devices vbd.

[2013-03-13 13:04:51 1983] DEBUG (DevController:144) Waiting for 51712.

[2013-03-13 13:04:51 1983] DEBUG (DevController:628) hotplugStatusCallback /local/domain/0/backend/vbd/4/51712/hotplug$

[2013-03-13 13:04:51 1983] DEBUG (DevController:642) hotplugStatusCallback 1.

[2013-03-13 13:04:51 1983] DEBUG (DevController:139) Waiting for devices irq.

[2013-03-13 13:04:51 1983] DEBUG (DevController:139) Waiting for devices vfb.

[2013-03-13 13:04:51 1983] DEBUG (DevController:139) Waiting for devices pci.

[2013-03-13 13:04:51 1983] DEBUG (DevController:139) Waiting for devices vusb.

[2013-03-13 13:04:51 1983] DEBUG (DevController:139) Waiting for devices vtpm.

[2013-03-13 13:04:51 1983] INFO (XendDomain:1225) Domain Sb-Voip1-DomU (4) unpaused.

[2013-03-13 13:20:31 1983] DEBUG (XendDomainInfo:3077) XendDomainInfo.destroy: domid=4

[2013-03-13 13:20:32 1983] DEBUG (XendDomainInfo:2402) Destroying device model

[2013-03-13 13:20:32 1983] DEBUG (XendDomainInfo:2409) Releasing devices

[2013-03-13 13:20:32 1983] DEBUG (XendDomainInfo:2415) Removing vif/0

[2013-03-13 13:20:32 1983] DEBUG (XendDomainInfo:2409) Releasing devices

[2013-03-13 13:20:32 1983] DEBUG (XendDomainInfo:2415) Removing vif/0

[2013-03-13 13:20:32 1983] DEBUG (XendDomainInfo:1276) XendDomainInfo.destroyDevice: deviceClass = vif, device = vif/0

[2013-03-13 13:20:32 1983] DEBUG (XendDomainInfo:2415) Removing console/0

[2013-03-13 13:20:32 1983] DEBUG (XendDomainInfo:1276) XendDomainInfo.destroyDevice: deviceClass = console, device = c$

[2013-03-13 13:20:32 1983] DEBUG (XendDomainInfo:2415) Removing vbd/51712

[2013-03-13 13:20:32 1983] DEBUG (XendDomainInfo:1276) XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/5$

[2013-03-13 13:20:32 1983] DEBUG (XendDomainInfo:2407) No device model

[2013-03-13 13:20:32 1983] DEBUG (XendDomainInfo:2409) Releasing devices

[2013-03-13 13:20:32 1983] DEBUG (XendDomainInfo:2415) Removing vif/0

[2013-03-13 13:20:32 1983] DEBUG (XendDomainInfo:1276) XendDomainInfo.destroyDevice: deviceClass = vif, device = vif/0

[2013-03-13 13:20:32 1983] DEBUG (XendDomainInfo:2415) Removing vbd/51712

[2013-03-13 13:20:32 1983] DEBUG (XendDomainInfo:1276) XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/5$

[2013-03-13 13:23:03 1983] DEBUG (XendDomainInfo:103) XendDomainInfo.create(['vm', ['name', 'Sb-Voip1-DomU'], ['memory$

[2013-03-13 13:23:03 1983] DEBUG (XendDomainInfo:2499) XendDomainInfo.constructDomain

[2013-03-13 13:23:03 1983] DEBUG (balloon:187) Balloon: 2058700 KiB free; need 16384; done.

[2013-03-13 13:23:03 1983] DEBUG (XendDomain:476) Adding Domain: 5

[2013-03-13 13:23:03 1983] DEBUG (XendDomainInfo:2842) XendDomainInfo.initDomain: 5 256

[2013-03-13 13:23:03 1983] INFO (XendDomainInfo:3276) Mounting drbd-vm on /dev/xvdp.

[2013-03-13 13:23:03 1983] DEBUG (DevController:95) DevController: writing {'backend-id': '0', 'virtual-device': '5195$

[2013-03-13 13:23:03 1983] DEBUG (DevController:97) DevController: writing {'domain': 'Domain-0', 'frontend': '/local/$

[2013-03-13 13:23:03 1983] DEBUG (DevController:144) Waiting for 51952.

[2013-03-13 13:23:03 1983] DEBUG (DevController:628) hotplugStatusCallback /local/domain/0/backend/vbd/0/51952/hotplug$

[2013-03-13 13:24:43 1983] ERROR (XendDomainInfo:3993) Device 51952 (vbd) could not be connected. Hotplug scripts not $

Traceback (most recent call last):

[2013-03-13 13:24:43 1983] ERROR (XendDomainInfo:3993) Device 51952 (vbd) could not be connected. Hotplug scripts not $

Traceback (most recent call last):

File "/usr/local/lib/python2.7/dist-packages/xen/xend/XendDomainInfo.py", line 3989, in create_vbd

self._waitForDevice(dev_type, devid)

File "/usr/local/lib/python2.7/dist-packages/xen/xend/XendDomainInfo.py", line 2330, in _waitForDevice

return self.getDeviceController(deviceClass).waitForDevice(devid)

File "/usr/local/lib/python2.7/dist-packages/xen/xend/server/DevController.py", line 155, in waitForDevice

(devid, self.deviceClass))

VmError: Device 51952 (vbd) could not be connected. Hotplug scripts not working.

[2013-03-13 13:24:43 1983] ERROR (XendDomainInfo:488) VM start failed

Traceback (most recent call last):

File "/usr/local/lib/python2.7/dist-packages/xen/xend/XendDomainInfo.py", line 474, in start

XendTask.log_progress(31, 60, self._initDomain)

File "/usr/local/lib/python2.7/dist-packages/xen/xend/XendTask.py", line 209, in log_progress

retval = func(*args, **kwds)

File "/usr/local/lib/python2.7/dist-packages/xen/xend/XendDomainInfo.py", line 2844, in _initDomain

self._configureBootloader()

File "/usr/local/lib/python2.7/dist-packages/xen/xend/XendDomainInfo.py", line 3285, in _configureBootloader

mounted_vbd_uuid = dom0.create_vbd(vbd, disk);

File "/usr/local/lib/python2.7/dist-packages/xen/xend/XendDomainInfo.py", line 3989, in create_vbd

self._waitForDevice(dev_type, devid)

File "/usr/local/lib/python2.7/dist-packages/xen/xend/XendDomainInfo.py", line 2330, in _waitForDevice

return self.getDeviceController(deviceClass).waitForDevice(devid)

File "/usr/local/lib/python2.7/dist-packages/xen/xend/server/DevController.py", line 155, in waitForDevice

(devid, self.deviceClass))

File "/usr/local/lib/python2.7/dist-packages/xen/xend/server/DevController.py", line 155, in waitForDevice

(devid, self.deviceClass))

VmError: Device 51952 (vbd) could not be connected. Hotplug scripts not working.

[2013-03-13 13:24:43 1983] DEBUG (XendDomainInfo:3077) XendDomainInfo.destroy: domid=5

[2013-03-13 13:24:43 1983] DEBUG (XendDomainInfo:2407) No device model

[2013-03-13 13:24:43 1983] DEBUG (XendDomainInfo:2409) Releasing devices

[2013-03-13 13:24:43 1983] ERROR (XendDomainInfo:108) Domain construction failed

Traceback (most recent call last):

File "/usr/local/lib/python2.7/dist-packages/xen/xend/XendDomainInfo.py", line 106, in create

vm.start()

File "/usr/local/lib/python2.7/dist-packages/xen/xend/XendDomainInfo.py", line 474, in start

XendTask.log_progress(31, 60, self._initDomain)

File "/usr/local/lib/python2.7/dist-packages/xen/xend/XendTask.py", line 209, in log_progress

retval = func(*args, **kwds)

File "/usr/local/lib/python2.7/dist-packages/xen/xend/XendDomainInfo.py", line 2844, in _initDomain

self._configureBootloader()

File "/usr/local/lib/python2.7/dist-packages/xen/xend/XendDomainInfo.py", line 3285, in _configureBootloader

mounted_vbd_uuid = dom0.create_vbd(vbd, disk);

File "/usr/local/lib/python2.7/dist-packages/xen/xend/XendDomainInfo.py", line 3989, in create_vbd

self._waitForDevice(dev_type, devid)

File "/usr/local/lib/python2.7/dist-packages/xen/xend/XendDomainInfo.py", line 2330, in _waitForDevice

return self.getDeviceController(deviceClass).waitForDevice(devid)

File "/usr/local/lib/python2.7/dist-packages/xen/xend/server/DevController.py", line 155, in waitForDevice

(devid, self.deviceClass))

VmError: Device 51952 (vbd) could not be connected. Hotplug scripts not working.

(devid, self.deviceClass))

VmError: Device 51952 (vbd) could not be connected. Hotplug scripts not working.

Regards,

Agya

On Wed, Mar 13, 2013 at 1:14 PM, agya naila <agya.naila@xxxxxxxxx> wrote:

I am not sure its due to high load in my case since there is still no high load in server. I didn't run any program that have high load and no client that accessing this server. I am suspecting the hotplug script. In my xend.log here is the logs :

server1@server1:~$ sudo tail /var/log/xen/xend.log
[2013-03-13 13:04:51 1983] DEBUG (DevController:144) Waiting for 51712.
[2013-03-13 13:04:51 1983] DEBUG (DevController:628) hotplugStatusCallback /local/domain/0/backend/vbd/4/51712/hotplug-status.

[2013-03-13 13:04:51 1983] DEBUG (DevController:628) hotplugStatusCallback /local/domain/0/backend/vbd/4/51712/hotplug-status.
[2013-03-13 13:04:51 1983] DEBUG (DevController:642) hotplugStatusCallback 1.

[2013-03-13 13:04:51 1983] DEBUG (DevController:139) Waiting for devices irq.
[2013-03-13 13:04:51 1983] DEBUG (DevController:139) Waiting for devices vfb.
[2013-03-13 13:04:51 1983] DEBUG (DevController:139) Waiting for devices pci.

[2013-03-13 13:04:51 1983] DEBUG (DevController:139) Waiting for devices vusb.
[2013-03-13 13:04:51 1983] DEBUG (DevController:139) Waiting for devices vtpm.
[2013-03-13 13:04:51 1983] INFO (XendDomain:1225) Domain DomU (4) unpaused.

any hints ?

regards,

Agya

On Wed, Mar 6, 2013 at 4:12 PM, Aaron Cossey <aaron.cossey@xxxxxxxxx> wrote:

I've encountered this frequently due to high io load. If you have monitoring of load and io, did you see anything happen just before these errors started in the logs?

Aaron Cossey
aaron.cossey@xxxxxxxxx

On Wed, Mar 6, 2013 at 1:35 PM, agya naila <agya.naila@xxxxxxxxx> wrote:

Hi all,

Today I got problem below and my domU become unresponsive and I should restart the pc to make it running properly again.

[ 240.172092] INFO: task kworker/u:0:5 blocked for more than 120 seconds.

[ 240.172110] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 240.172376] INFO: task jbd2/xvda1-8:153 blocked for more than 120 seconds.
[ 240.172388] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

[ 240.172610] INFO: task flush-202:0:421 blocked for more than 120 seconds.
[ 240.172619] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 240.172946] INFO: task freeswitch:1030 blocked for more than 120 seconds.

[ 240.172957] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 240.173215] INFO: task freeswitch:1033 blocked for more than 120 seconds.
[ 240.173225] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

[ 240.173454] INFO: task freeswitch:1036 blocked for more than 120 seconds.
[ 240.173464] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 240.173670] INFO: task freeswitch:1044 blocked for more than 120 seconds.

[ 240.173680] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 240.173828] INFO: task freeswitch:1046 blocked for more than 120 seconds.
[ 240.173839] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

[ 240.173986] INFO: task freeswitch:1047 blocked for more than 120 seconds.
[ 240.173996] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

Does any body have clue regarding this problem?

Regards,

Agya

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

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

Re: [Xen-users] Task blocked for more than 120 seconds.