Attachment 574125 Details for Bug 808655 – logs when the call hangs

logs when the call hangs

vdsm.log (text/plain), 8.51 KB, created by wenchao xia on 2012-03-31 03:26:24 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: wenchao xia

Created: 2012-03-31 03:26:24 UTC

Size: 8.51 KB

patch

obsolete

>MainThread::INFO::2012-03-31 11:03:29,335::vdsm::70::vds::(run) I am the actual vdsm 4.9-0
>MainThread::DEBUG::2012-03-31 11:03:29,584::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'Storage'
>MainThread::DEBUG::2012-03-31 11:03:29,585::threadPool::45::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0
>MainThread::DEBUG::2012-03-31 11:03:29,607::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /bin/cat /etc/multipath.conf' (cwd None)
>MainThread::DEBUG::2012-03-31 11:03:29,619::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2012-03-31 11:03:29,619::multipath::101::Storage.Multipath::(isEnabled) Current revision of multipath.conf detected, preserving
>MainThread::DEBUG::2012-03-31 11:03:29,620::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None)
>MainThread::DEBUG::2012-03-31 11:03:29,637::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2012-03-31 11:03:29,637::lvm::333::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex
>MainThread::DEBUG::2012-03-31 11:03:29,639::__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-03-31 11:03:29,660::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2012-03-31 11:03:29,661::lvm::356::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex
>MainThread::DEBUG::2012-03-31 11:03:29,661::lvm::366::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
>MainThread::DEBUG::2012-03-31 11:03:29,662::__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-03-31 11:03:29,684::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>MainThread::DEBUG::2012-03-31 11:03:29,685::lvm::393::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
>MainThread::DEBUG::2012-03-31 11:03:29,685::__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-03-31 11:03:29,708::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2012-03-31 11:03:29,708::misc::1101::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
>MainThread::INFO::2012-03-31 11:03:29,710::dispatcher::118::Storage.Dispatcher::(__init__) Starting StorageDispatcher...
>Thread-12::DEBUG::2012-03-31 11:03:29,710::misc::1103::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-03-31 11:03:29,711::misc::1101::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
>Thread-12::DEBUG::2012-03-31 11:03:29,711::misc::1103::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-03-31 11:03:29,712::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
>MainThread::DEBUG::2012-03-31 11:03:29,717::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/pgrep -xf ksmd' (cwd None)
>Thread-12::DEBUG::2012-03-31 11:03:29,734::__init__::1241::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21
>MainThread::DEBUG::2012-03-31 11:03:29,735::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-03-31 11:03:29,735::misc::1111::SamplingMethod::(__call__) Returning last result
>Thread-12::DEBUG::2012-03-31 11:03:29,736::supervdsm::83::SuperVdsmProxy::(_killSupervdsm) Could not kill old Super Vdsm [Errno 2] No such file or directory: '/var/run/vdsm/svdsm.pid'
>Thread-12::DEBUG::2012-03-31 11:03:29,736::supervdsm::71::SuperVdsmProxy::(_launchSupervdsm) Launching Super Vdsm
>Thread-12::DEBUG::2012-03-31 11:03:29,736::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /usr/bin/python /usr/share/vdsm/supervdsmServer.pyc 5a3f9191-6111-4402-a5f5-9966b0ef9794 18061' (cwd None)
>MainThread::INFO::2012-03-31 11:03:29,739::vmChannels::139::vds::(settimeout) Setting channels' timeout to 30 seconds.
>VM Channels Listener::INFO::2012-03-31 11:03:29,741::vmChannels::127::vds::(run) Starting VM channels listener thread.
>Thread-14::DEBUG::2012-03-31 11:03:30,040::BindingXMLRPC::167::vds::(wrapper) [127.0.0.1]
>Thread-14::DEBUG::2012-03-31 11:03:30,041::task::588::TaskManager.Task::(_updateState) Task=`d65608d6-35ae-43c7-9f4c-f95bd74a5a58`::moving from state init -> state preparing
>Thread-14::INFO::2012-03-31 11:03:30,041::logUtils::37::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=4, spUUID='my favorite pet', conList=[{'connection': '/var/lib/vdsm/storage', 'id': 1}], options=None)
>Thread-14::DEBUG::2012-03-31 11:03:30,042::lvm::474::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-14::DEBUG::2012-03-31 11:03:30,042::lvm::476::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-14::DEBUG::2012-03-31 11:03:30,043::lvm::486::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-14::DEBUG::2012-03-31 11:03:30,043::lvm::488::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-14::DEBUG::2012-03-31 11:03:30,043::lvm::507::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-14::DEBUG::2012-03-31 11:03:30,043::lvm::509::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-14::INFO::2012-03-31 11:03:30,044::logUtils::39::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': 1}]}
>Thread-14::DEBUG::2012-03-31 11:03:30,044::task::1172::TaskManager.Task::(prepare) Task=`d65608d6-35ae-43c7-9f4c-f95bd74a5a58`::finished: {'statuslist': [{'status': 0, 'id': 1}]}
>Thread-14::DEBUG::2012-03-31 11:03:30,044::task::588::TaskManager.Task::(_updateState) Task=`d65608d6-35ae-43c7-9f4c-f95bd74a5a58`::moving from state preparing -> state finished
>Thread-14::DEBUG::2012-03-31 11:03:30,044::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-14::DEBUG::2012-03-31 11:03:30,044::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-14::DEBUG::2012-03-31 11:03:30,045::task::978::TaskManager.Task::(_decref) Task=`d65608d6-35ae-43c7-9f4c-f95bd74a5a58`::ref 0 aborting False
>Thread-15::DEBUG::2012-03-31 11:03:30,046::BindingXMLRPC::167::vds::(wrapper) [127.0.0.1]
>Thread-15::DEBUG::2012-03-31 11:03:30,047::task::588::TaskManager.Task::(_updateState) Task=`593b7ec9-9db2-4d55-9112-62774aee8260`::moving from state init -> state preparing
>Thread-15::INFO::2012-03-31 11:03:30,047::logUtils::37::dispatcher::(wrapper) Run and protect: createStorageDomain(storageType=4, sdUUID='b9c4821e-e9c0-4dd4-8393-c59b82c9cd29', domainName='my local domain', typeSpecificArg='/var/lib/vdsm/storage', domClass=1, domVersion=0, options=None)
>Thread-15::DEBUG::2012-03-31 11:03:30,047::misc::1101::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)

Actions: View

Attachments on bug 808655: 574124 | 574125