The attachment is the log. Vdsm was built on:
19981e1bee497cded822b184180d661b7cb625bd
BZ#773210 - Avoid infinite loop when delete volume failed during the merge
with following change:
vdsm.spec.in:
-Requires: lvm2 >= 2.02.95
+Requires: lvm2 >= 2.02.86
-Requires: libvirt >= 0.9.10-9
-Requires: libvirt-python >= 0.9.10-9
+Requires: libvirt >= 0.9.6
+Requires: libvirt-python >= 0.9.6
I don't have latest package of that, so changed them, but they
seems not related to the issue.
----- Original Message -----
δΊ 2012-4-12 14:54, Ayal Baron ει:
----- Original Message -----
I am using Fedora 16 with default python2.7.2 installed, and found
sometimes vdsm hanged at
vdsm/storage/misc.py, func execFunc:
p = subprocess.Popen(command, close_fds=True, cwd=cwd,
stdin=infile, stdout=outfile,
stderr=subprocess.PIPE,
env=env)
Stopped command could be anything, most likely is
"Thread-12::DEBUG::2012-04-12
11:18:08,995::__init__::1241::Storage.Misc.excCmd::(_log)
'/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)"
during vdsm booting up procedure. This happens only when an other
thread is started at the same time by calling
threading.thread.start(), which I found in clientIF._init():
self._hostStats.start()
When it happens , there would be two vdsm showed in ps
command,:
vdsm 13794 1 0 11:18 ? 00:00:00 /bin/bash -e
/usr/share/vdsm/respawn --minlifetime 10 --daemon --masterpid
/var/run/vdsm/respawn.pid /usr/share/vdsm/vdsm
vdsm 13797 13794 0 11:18 ? 00:00:00 /usr/bin/python
/usr/share/vdsm/vdsm
vdsm 13837 13797 0 11:18 ? 00:00:00 /usr/bin/python
/usr/share/vdsm/vdsm
Does anyone could give some idea about it? I made my own
testing
.py program calling misc.execFunc in one thread, and starting
an
other thread by start() in main thread, same thing happens
with
little chance, so I guess it is a bug in python threading and
pipe, planning to change vdsm threading class to work around
this.
Do you have abrt package installed?
yes, and removed all abrt packages testing again, problem still
happens.
[root@oVirtPC xiawenc]# rpm -qa | grep abrt
[root@oVirtPC xiawenc]#
[root@oVirtPC xiawenc]# rpm -qa | grep vdsm
vdsm-cli-4.9.6-0.68.git19981e1.fc16.noarch
vdsm-4.9.6-0.68.git19981e1.fc16.x86_64
vdsm-debuginfo-4.9.6-0.68.git19981e1.fc16.x86_64
vdsm-python-4.9.6-0.68.git19981e1.fc16.noarch
Adam also metioned abrt package before, what problem it would
trick?
abrt had a bug where in some cases it would read from a socket that was never
written to without a timeout so it would hang.
The maintainer introduced a patch earlier this week but I'm not sure it's
accepted yet.
Can you attach vdsm.log?
_______________________________________________
vdsm-devel mailing list
vdsm-devel@lists.fedorahosted.org
https://fedorahosted.org/mailman/listinfo/vdsm-devel
MainThread::INFO::2012-04-12 16:51:14,876::vdsm::70::vds::(run) I am the actual
vdsm 4.9-0
MainThread::DEBUG::2012-04-12
16:51:15,142::resourceManager::379::ResourceManager::(registerNamespace)
Registering namespace 'Storage'
MainThread::DEBUG::2012-04-12
16:51:15,142::threadPool::45::Misc.ThreadPool::(__init__) Enter - numThreads:
10.0, waitTimeout: 3, maxTasks: 500.0
MainThread::DEBUG::2012-04-12
16:51:15,160::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n
/bin/cat /etc/multipath.conf' (cwd None)
MainThread::DEBUG::2012-04-12
16:51:15,173::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '';
<rc> = 0
MainThread::DEBUG::2012-04-12
16:51:15,174::multipath::101::Storage.Multipath::(isEnabled) Current revision
of multipath.conf detected, preserving
MainThread::DEBUG::2012-04-12
16:51:15,174::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n
/sbin/lvm dumpconfig global/locking_type' (cwd None)
MainThread::DEBUG::2012-04-12
16:51:15,186::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '';
<rc> = 0
MainThread::DEBUG::2012-04-12
16:51:15,187::lvm::333::OperationMutex::(_reloadpvs) Operation 'lvm reload
operation' got the operation mutex
MainThread::DEBUG::2012-04-12
16:51:15,187::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n
/sbin/lvm pvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"]
ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3
filter = [ \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1
wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings
--units b --nosuffix --separator | -o
uuid,name,size,vg_name,vg_uuid,pe_start,pe_count,pe_alloc_count,mda_count,dev_size'
(cwd None)
MainThread::DEBUG::2012-04-12
16:51:15,202::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '';
<rc> = 0
MainThread::DEBUG::2012-04-12
16:51:15,202::lvm::356::OperationMutex::(_reloadpvs) Operation 'lvm reload
operation' released the operation mutex
MainThread::DEBUG::2012-04-12
16:51:15,203::lvm::366::OperationMutex::(_reloadvgs) Operation 'lvm reload
operation' got the operation mutex
MainThread::DEBUG::2012-04-12
16:51:15,203::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n
/sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"]
ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3
filter = [ \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1
wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings
--units b --nosuffix --separator | -o
uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free'
(cwd None)
MainThread::DEBUG::2012-04-12
16:51:15,217::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '
No volume groups found\n'; <rc> = 0
MainThread::DEBUG::2012-04-12
16:51:15,218::lvm::393::OperationMutex::(_reloadvgs) Operation 'lvm reload
operation' released the operation mutex
MainThread::DEBUG::2012-04-12
16:51:15,218::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n
/sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"]
ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3
filter = [ \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1
wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings
--units b --nosuffix --separator | -o
uuid,name,vg_name,attr,size,seg_start_pe,devices,tags' (cwd None)
MainThread::DEBUG::2012-04-12
16:51:15,233::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '
No volume groups found\n'; <rc> = 0
MainThread::INFO::2012-04-12
16:51:15,234::dispatcher::95::Storage.Dispatcher::(__init__) Starting
StorageDispatcher...
Thread-12::DEBUG::2012-04-12
16:51:15,235::misc::1101::SamplingMethod::(__call__) Trying to enter sampling
method (storage.sdc.refreshStorage)
Thread-12::DEBUG::2012-04-12
16:51:15,235::misc::1103::SamplingMethod::(__call__) Got in to sampling method
Thread-12::DEBUG::2012-04-12
16:51:15,235::misc::1101::SamplingMethod::(__call__) Trying to enter sampling
method (storage.iscsi.rescan)
Thread-12::DEBUG::2012-04-12
16:51:15,236::misc::1103::SamplingMethod::(__call__) Got in to sampling method
Thread-12::DEBUG::2012-04-12
16:51:15,236::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n
/sbin/iscsiadm -m session -R' (cwd None)
MainThread::DEBUG::2012-04-12
16:51:15,239::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/pgrep -xf
ksmd' (cwd None)
MainThread::DEBUG::2012-04-12
16:51:15,252::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '';
<rc> = 0
MainThread::INFO::2012-04-12 16:51:15,253::vmChannels::139::vds::(settimeout)
Setting channels' timeout to 30 seconds.
VM Channels Listener::INFO::2012-04-12
16:51:15,255::vmChannels::127::vds::(run) Starting VM channels listener thread.
_______________________________________________
vdsm-devel mailing list
vdsm-devel@lists.fedorahosted.org
https://fedorahosted.org/mailman/listinfo/vdsm-devel
