Attachment 852660 Details for Bug 1055437 – vdsm log

vdsm log

vdsmhost3.log (text/x-log), 39.28 KB, created by Meital Bourvine on 2014-01-20 09:26:34 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Meital Bourvine

Created: 2014-01-20 09:26:34 UTC

Size: 39.28 KB

patch

obsolete

>Dummy-1064173::DEBUG::2014-01-20 10:00:17,779::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail) 'dd if=/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000' (cwd None)
>Dummy-1064173::DEBUG::2014-01-20 10:00:17,987::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail) SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0775934 s, 13.2 MB/s\n'; <rc> = 0
>Thread-1693802::DEBUG::2014-01-20 10:00:18,942::task::579::TaskManager.Task::(_updateState) Task=`1123b19e-7386-4766-9747-2a209d65dec3`::moving from state init -> state preparing
>Thread-1693802::INFO::2014-01-20 10:00:18,943::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-1693802::INFO::2014-01-20 10:00:18,944::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {u'83b1867f-4aea-400e-9ce0-efbd5add4216': {'delay': '0.000231436', 'lastCheck': '2.0', 'code': 0, 'valid': True, 'version': 0}, u'94de241c-bf5c-4630-9af3-7e31b902ae77': {'delay': '0.00145164', 'lastCheck': '5.5', 'code': 0, 'valid': True, 'version': 3}, u'f3fd055b-2764-44ed-9d77-81bd58984842': {'delay': '0.000435741', 'lastCheck': '4.1', 'code': 0, 'valid': True, 'version': 3}, u'f8ddd1d1-5266-493b-879b-f79c128751e2': {'delay': '0.000377895', 'lastCheck': '3.4', 'code': 0, 'valid': True, 'version': 3}, u'50cf24a4-d1ef-4105-a9a5-b81d91339175': {'delay': '0.000388291', 'lastCheck': '3.0', 'code': 0, 'valid': True, 'version': 0}}
>Thread-1693802::DEBUG::2014-01-20 10:00:18,945::task::1168::TaskManager.Task::(prepare) Task=`1123b19e-7386-4766-9747-2a209d65dec3`::finished: {u'83b1867f-4aea-400e-9ce0-efbd5add4216': {'delay': '0.000231436', 'lastCheck': '2.0', 'code': 0, 'valid': True, 'version': 0}, u'94de241c-bf5c-4630-9af3-7e31b902ae77': {'delay': '0.00145164', 'lastCheck': '5.5', 'code': 0, 'valid': True, 'version': 3}, u'f3fd055b-2764-44ed-9d77-81bd58984842': {'delay': '0.000435741', 'lastCheck': '4.1', 'code': 0, 'valid': True, 'version': 3}, u'f8ddd1d1-5266-493b-879b-f79c128751e2': {'delay': '0.000377895', 'lastCheck': '3.4', 'code': 0, 'valid': True, 'version': 3}, u'50cf24a4-d1ef-4105-a9a5-b81d91339175': {'delay': '0.000388291', 'lastCheck': '3.0', 'code': 0, 'valid': True, 'version': 0}}
>Thread-1693802::DEBUG::2014-01-20 10:00:18,945::task::579::TaskManager.Task::(_updateState) Task=`1123b19e-7386-4766-9747-2a209d65dec3`::moving from state preparing -> state finished
>Thread-1693802::DEBUG::2014-01-20 10:00:18,946::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-1693802::DEBUG::2014-01-20 10:00:18,946::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-1693802::DEBUG::2014-01-20 10:00:18,946::task::974::TaskManager.Task::(_decref) Task=`1123b19e-7386-4766-9747-2a209d65dec3`::ref 0 aborting False
>VM Channels Listener::DEBUG::2014-01-20 10:00:19,215::vmChannels::91::vds::(_handle_timeouts) Timeout on fileno 141.
>Dummy-1064173::DEBUG::2014-01-20 10:00:20,014::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail) 'dd if=/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000' (cwd None)
>Dummy-1064173::DEBUG::2014-01-20 10:00:20,137::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail) SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0450542 s, 22.7 MB/s\n'; <rc> = 0
>Dummy-1064173::DEBUG::2014-01-20 10:00:22,158::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail) 'dd if=/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000' (cwd None)
>Dummy-1064173::DEBUG::2014-01-20 10:00:22,310::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail) SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0720033 s, 14.2 MB/s\n'; <rc> = 0
>Thread-479::DEBUG::2014-01-20 10:00:23,415::blockSD::595::Storage.Misc.excCmd::(getReadDelay) '/bin/dd iflag=direct if=/dev/94de241c-bf5c-4630-9af3-7e31b902ae77/metadata bs=4096 count=1' (cwd None)
>Thread-479::DEBUG::2014-01-20 10:00:23,442::blockSD::595::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '1+0 records in\n1+0 records out\n4096 bytes (4.1 kB) copied, 0.000767641 s, 5.3 MB/s\n'; <rc> = 0
>Dummy-1064173::DEBUG::2014-01-20 10:00:24,331::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail) 'dd if=/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000' (cwd None)
>Dummy-1064173::DEBUG::2014-01-20 10:00:24,490::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail) SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0618786 s, 16.5 MB/s\n'; <rc> = 0
>Thread-23::DEBUG::2014-01-20 10:00:24,825::blockSD::595::Storage.Misc.excCmd::(getReadDelay) '/bin/dd iflag=direct if=/dev/f3fd055b-2764-44ed-9d77-81bd58984842/metadata bs=4096 count=1' (cwd None)
>Thread-23::DEBUG::2014-01-20 10:00:24,853::blockSD::595::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '1+0 records in\n1+0 records out\n4096 bytes (4.1 kB) copied, 0.000387667 s, 10.6 MB/s\n'; <rc> = 0
>Thread-24::DEBUG::2014-01-20 10:00:25,577::blockSD::595::Storage.Misc.excCmd::(getReadDelay) '/bin/dd iflag=direct if=/dev/f8ddd1d1-5266-493b-879b-f79c128751e2/metadata bs=4096 count=1' (cwd None)
>Thread-24::DEBUG::2014-01-20 10:00:25,603::blockSD::595::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '1+0 records in\n1+0 records out\n4096 bytes (4.1 kB) copied, 0.000396981 s, 10.3 MB/s\n'; <rc> = 0
>Thread-28::DEBUG::2014-01-20 10:00:25,961::fileSD::239::Storage.Misc.excCmd::(getReadDelay) '/bin/dd iflag=direct if=/rhev/data-center/mnt/vega.brusselsairport.aero:_var_lib_exports_iso/50cf24a4-d1ef-4105-a9a5-b81d91339175/dom_md/metadata bs=4096 count=1' (cwd None)
>Thread-28::DEBUG::2014-01-20 10:00:25,985::fileSD::239::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n442 bytes (442 B) copied, 0.000467821 s, 945 kB/s\n'; <rc> = 0
>Dummy-1064173::DEBUG::2014-01-20 10:00:26,518::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail) 'dd if=/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000' (cwd None)
>Dummy-1064173::DEBUG::2014-01-20 10:00:26,663::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail) SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0668151 s, 15.3 MB/s\n'; <rc> = 0
>Thread-22::DEBUG::2014-01-20 10:00:26,947::fileSD::239::Storage.Misc.excCmd::(getReadDelay) '/bin/dd iflag=direct if=/rhev/data-center/mnt/buran.brusselsairport.aero:_root_NfsStorageBuran/83b1867f-4aea-400e-9ce0-efbd5add4216/dom_md/metadata bs=4096 count=1' (cwd None)
>Thread-22::DEBUG::2014-01-20 10:00:26,971::fileSD::239::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n378 bytes (378 B) copied, 0.000218043 s, 1.7 MB/s\n'; <rc> = 0
>Thread-1693806::DEBUG::2014-01-20 10:00:27,580::BindingXMLRPC::177::vds::(wrapper) client [10.110.57.30]
>Thread-1693806::DEBUG::2014-01-20 10:00:27,581::task::579::TaskManager.Task::(_updateState) Task=`9bfc8b44-a3a7-416a-9650-37f0d80d0218`::moving from state init -> state preparing
>Thread-1693806::INFO::2014-01-20 10:00:27,582::logUtils::44::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='5849b030-626e-47cb-ad90-3ce782d831b3', options=None)
>Thread-1693806::INFO::2014-01-20 10:00:27,582::logUtils::47::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'SPM', 'spmLver': 13}}
>Thread-1693806::DEBUG::2014-01-20 10:00:27,583::task::1168::TaskManager.Task::(prepare) Task=`9bfc8b44-a3a7-416a-9650-37f0d80d0218`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'SPM', 'spmLver': 13}}
>Thread-1693806::DEBUG::2014-01-20 10:00:27,583::task::579::TaskManager.Task::(_updateState) Task=`9bfc8b44-a3a7-416a-9650-37f0d80d0218`::moving from state preparing -> state finished
>Thread-1693806::DEBUG::2014-01-20 10:00:27,583::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-1693806::DEBUG::2014-01-20 10:00:27,583::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-1693806::DEBUG::2014-01-20 10:00:27,584::task::974::TaskManager.Task::(_decref) Task=`9bfc8b44-a3a7-416a-9650-37f0d80d0218`::ref 0 aborting False
>Thread-1693807::DEBUG::2014-01-20 10:00:27,588::BindingXMLRPC::177::vds::(wrapper) client [10.110.57.30]
>Thread-1693807::DEBUG::2014-01-20 10:00:27,589::task::579::TaskManager.Task::(_updateState) Task=`72e747dc-ee32-4056-b97c-e7d35c80e3ed`::moving from state init -> state preparing
>Thread-1693807::INFO::2014-01-20 10:00:27,589::logUtils::44::dispatcher::(wrapper) Run and protect: getStoragePoolInfo(spUUID='5849b030-626e-47cb-ad90-3ce782d831b3', options=None)
>Thread-1693807::DEBUG::2014-01-20 10:00:27,590::resourceManager::197::ResourceManager.Request::(__init__) ResName=`Storage.5849b030-626e-47cb-ad90-3ce782d831b3`ReqID=`2dd2acf6-b7b9-4921-bf29-e1df63a6977e`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '2547' at 'getStoragePoolInfo'
>Thread-1693807::DEBUG::2014-01-20 10:00:27,590::resourceManager::541::ResourceManager::(registerResource) Trying to register resource 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3' for lock type 'shared'
>Thread-1693807::DEBUG::2014-01-20 10:00:27,590::resourceManager::600::ResourceManager::(registerResource) Resource 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3' is free. Now locking as 'shared' (1 active user)
>Thread-1693807::DEBUG::2014-01-20 10:00:27,591::resourceManager::237::ResourceManager.Request::(grant) ResName=`Storage.5849b030-626e-47cb-ad90-3ce782d831b3`ReqID=`2dd2acf6-b7b9-4921-bf29-e1df63a6977e`::Granted request
>Thread-1693807::DEBUG::2014-01-20 10:00:27,593::task::811::TaskManager.Task::(resourceAcquired) Task=`72e747dc-ee32-4056-b97c-e7d35c80e3ed`::_resourcesAcquired: Storage.5849b030-626e-47cb-ad90-3ce782d831b3 (shared)
>Thread-1693807::DEBUG::2014-01-20 10:00:27,594::task::974::TaskManager.Task::(_decref) Task=`72e747dc-ee32-4056-b97c-e7d35c80e3ed`::ref 1 aborting False
>Thread-1693807::INFO::2014-01-20 10:00:27,595::logUtils::47::dispatcher::(wrapper) Run and protect: getStoragePoolInfo, Return response: {'info': {'spm_id': 1, 'master_uuid': 'f8ddd1d1-5266-493b-879b-f79c128751e2', 'name': 'Test-Dev', 'version': '3', 'domains': u'83b1867f-4aea-400e-9ce0-efbd5add4216:Active,94de241c-bf5c-4630-9af3-7e31b902ae77:Active,f3fd055b-2764-44ed-9d77-81bd58984842:Active,f8ddd1d1-5266-493b-879b-f79c128751e2:Active,50cf24a4-d1ef-4105-a9a5-b81d91339175:Active', 'pool_status': 'connected', 'isoprefix': '/rhev/data-center/mnt/vega.brusselsairport.aero:_var_lib_exports_iso/50cf24a4-d1ef-4105-a9a5-b81d91339175/images/11111111-1111-1111-1111-111111111111', 'type': 'ISCSI', 'master_ver': 1, 'lver': 13}, 'dominfo': {u'83b1867f-4aea-400e-9ce0-efbd5add4216': {'status': u'Active', 'diskfree': '5759723110400', 'alerts': [], 'version': 0, 'disktotal': '6185034973184'}, u'94de241c-bf5c-4630-9af3-7e31b902ae77': {'status': u'Active', 'diskfree': '409632505856', 'alerts': [], 'version': 3, 'disktotal': '595524059136'}, u'f3fd055b-2764-44ed-9d77-81bd58984842': {'status': u'Active', 'diskfree': '56639881216', 'alerts': [], 'version': 3, 'disktotal': '595524059136'}, u'f8ddd1d1-5266-493b-879b-f79c128751e2': {'status': u'Active', 'diskfree': '43889197056', 'alerts': [], 'version': 3, 'disktotal': '595524059136'}, u'50cf24a4-d1ef-4105-a9a5-b81d91339175': {'status': u'Active', 'diskfree': '4726980608', 'alerts': [], 'version': 0, 'disktotal': '21891121152'}}}
>Thread-1693807::DEBUG::2014-01-20 10:00:27,596::task::1168::TaskManager.Task::(prepare) Task=`72e747dc-ee32-4056-b97c-e7d35c80e3ed`::finished: {'info': {'spm_id': 1, 'master_uuid': 'f8ddd1d1-5266-493b-879b-f79c128751e2', 'name': 'Test-Dev', 'version': '3', 'domains': u'83b1867f-4aea-400e-9ce0-efbd5add4216:Active,94de241c-bf5c-4630-9af3-7e31b902ae77:Active,f3fd055b-2764-44ed-9d77-81bd58984842:Active,f8ddd1d1-5266-493b-879b-f79c128751e2:Active,50cf24a4-d1ef-4105-a9a5-b81d91339175:Active', 'pool_status': 'connected', 'isoprefix': '/rhev/data-center/mnt/vega.brusselsairport.aero:_var_lib_exports_iso/50cf24a4-d1ef-4105-a9a5-b81d91339175/images/11111111-1111-1111-1111-111111111111', 'type': 'ISCSI', 'master_ver': 1, 'lver': 13}, 'dominfo': {u'83b1867f-4aea-400e-9ce0-efbd5add4216': {'status': u'Active', 'diskfree': '5759723110400', 'alerts': [], 'version': 0, 'disktotal': '6185034973184'}, u'94de241c-bf5c-4630-9af3-7e31b902ae77': {'status': u'Active', 'diskfree': '409632505856', 'alerts': [], 'version': 3, 'disktotal': '595524059136'}, u'f3fd055b-2764-44ed-9d77-81bd58984842': {'status': u'Active', 'diskfree': '56639881216', 'alerts': [], 'version': 3, 'disktotal': '595524059136'}, u'f8ddd1d1-5266-493b-879b-f79c128751e2': {'status': u'Active', 'diskfree': '43889197056', 'alerts': [], 'version': 3, 'disktotal': '595524059136'}, u'50cf24a4-d1ef-4105-a9a5-b81d91339175': {'status': u'Active', 'diskfree': '4726980608', 'alerts': [], 'version': 0, 'disktotal': '21891121152'}}}
>Thread-1693807::DEBUG::2014-01-20 10:00:27,596::task::579::TaskManager.Task::(_updateState) Task=`72e747dc-ee32-4056-b97c-e7d35c80e3ed`::moving from state preparing -> state finished
>Thread-1693807::DEBUG::2014-01-20 10:00:27,596::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.5849b030-626e-47cb-ad90-3ce782d831b3': < ResourceRef 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3', isValid: 'True' obj: 'None'>}
>Thread-1693807::DEBUG::2014-01-20 10:00:27,597::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-1693807::DEBUG::2014-01-20 10:00:27,597::resourceManager::615::ResourceManager::(releaseResource) Trying to release resource 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3'
>Thread-1693807::DEBUG::2014-01-20 10:00:27,597::resourceManager::634::ResourceManager::(releaseResource) Released resource 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3' (0 active users)
>Thread-1693807::DEBUG::2014-01-20 10:00:27,598::resourceManager::640::ResourceManager::(releaseResource) Resource 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3' is free, finding out if anyone is waiting for it.
>Thread-1693807::DEBUG::2014-01-20 10:00:27,598::resourceManager::648::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3', Clearing records.
>Thread-1693807::DEBUG::2014-01-20 10:00:27,598::task::974::TaskManager.Task::(_decref) Task=`72e747dc-ee32-4056-b97c-e7d35c80e3ed`::ref 0 aborting False
>Dummy-1064173::DEBUG::2014-01-20 10:00:28,683::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail) 'dd if=/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000' (cwd None)
>Dummy-1064173::DEBUG::2014-01-20 10:00:28,816::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail) SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0463101 s, 22.1 MB/s\n'; <rc> = 0
>Thread-1541905::DEBUG::2014-01-20 10:00:29,567::task::579::TaskManager.Task::(_updateState) Task=`470cd79e-8f20-487b-8cb3-6a2a0a69f530`::moving from state init -> state preparing
>Thread-1541905::INFO::2014-01-20 10:00:29,568::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='f8ddd1d1-5266-493b-879b-f79c128751e2', spUUID='5849b030-626e-47cb-ad90-3ce782d831b3', imgUUID='f6f5d6ca-6f75-439f-93a4-b1aebd2e1d08', volUUID='b5e70268-9e87-4a8d-a14e-d45cfaa0f5c1', options=None)
>Thread-1541905::INFO::2014-01-20 10:00:29,568::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '10737418240', 'apparentsize': '10737418240'}
>Thread-1541905::DEBUG::2014-01-20 10:00:29,569::task::1168::TaskManager.Task::(prepare) Task=`470cd79e-8f20-487b-8cb3-6a2a0a69f530`::finished: {'truesize': '10737418240', 'apparentsize': '10737418240'}
>Thread-1541905::DEBUG::2014-01-20 10:00:29,569::task::579::TaskManager.Task::(_updateState) Task=`470cd79e-8f20-487b-8cb3-6a2a0a69f530`::moving from state preparing -> state finished
>Thread-1541905::DEBUG::2014-01-20 10:00:29,569::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-1541905::DEBUG::2014-01-20 10:00:29,569::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-1541905::DEBUG::2014-01-20 10:00:29,570::task::974::TaskManager.Task::(_decref) Task=`470cd79e-8f20-487b-8cb3-6a2a0a69f530`::ref 0 aborting False
>Thread-1541905::DEBUG::2014-01-20 10:00:29,570::task::579::TaskManager.Task::(_updateState) Task=`b7f8617f-18ab-485a-9262-62010d2c3c8d`::moving from state init -> state preparing
>Thread-1541905::INFO::2014-01-20 10:00:29,570::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='f8ddd1d1-5266-493b-879b-f79c128751e2', spUUID='5849b030-626e-47cb-ad90-3ce782d831b3', imgUUID='ef4e60f7-814c-47c7-a465-96882cdf93ea', volUUID='4e3b5438-dc22-4ef0-9c92-9b6a99aecd3a', options=None)
>Thread-1541905::INFO::2014-01-20 10:00:29,571::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '10737418240', 'apparentsize': '10737418240'}
>Thread-1541905::DEBUG::2014-01-20 10:00:29,571::task::1168::TaskManager.Task::(prepare) Task=`b7f8617f-18ab-485a-9262-62010d2c3c8d`::finished: {'truesize': '10737418240', 'apparentsize': '10737418240'}
>Thread-1541905::DEBUG::2014-01-20 10:00:29,572::task::579::TaskManager.Task::(_updateState) Task=`b7f8617f-18ab-485a-9262-62010d2c3c8d`::moving from state preparing -> state finished
>Thread-1541905::DEBUG::2014-01-20 10:00:29,572::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-1541905::DEBUG::2014-01-20 10:00:29,572::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-1541905::DEBUG::2014-01-20 10:00:29,572::task::974::TaskManager.Task::(_decref) Task=`b7f8617f-18ab-485a-9262-62010d2c3c8d`::ref 0 aborting False
>Thread-1101743::DEBUG::2014-01-20 10:00:29,869::task::579::TaskManager.Task::(_updateState) Task=`c4c234a5-e93a-48af-ba61-e9c11cf9cb32`::moving from state init -> state preparing
>Thread-1101743::INFO::2014-01-20 10:00:29,869::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='f8ddd1d1-5266-493b-879b-f79c128751e2', spUUID='5849b030-626e-47cb-ad90-3ce782d831b3', imgUUID='4896bc40-8903-4d76-8ef5-2329c84b8c24', volUUID='c5508b37-4273-417c-bdcf-3f03dbda1c56', options=None)
>Thread-1101743::INFO::2014-01-20 10:00:29,870::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '53687091200', 'apparentsize': '53687091200'}
>Thread-1101743::DEBUG::2014-01-20 10:00:29,870::task::1168::TaskManager.Task::(prepare) Task=`c4c234a5-e93a-48af-ba61-e9c11cf9cb32`::finished: {'truesize': '53687091200', 'apparentsize': '53687091200'}
>Thread-1101743::DEBUG::2014-01-20 10:00:29,870::task::579::TaskManager.Task::(_updateState) Task=`c4c234a5-e93a-48af-ba61-e9c11cf9cb32`::moving from state preparing -> state finished
>Thread-1101743::DEBUG::2014-01-20 10:00:29,870::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-1101743::DEBUG::2014-01-20 10:00:29,871::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-1101743::DEBUG::2014-01-20 10:00:29,871::task::974::TaskManager.Task::(_decref) Task=`c4c234a5-e93a-48af-ba61-e9c11cf9cb32`::ref 0 aborting False
>Dummy-1064173::DEBUG::2014-01-20 10:00:30,838::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail) 'dd if=/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000' (cwd None)
>Dummy-1064173::DEBUG::2014-01-20 10:00:30,967::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail) SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0492334 s, 20.8 MB/s\n'; <rc> = 0
>Dummy-1064173::DEBUG::2014-01-20 10:00:32,988::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail) 'dd if=/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000' (cwd None)
>Dummy-1064173::DEBUG::2014-01-20 10:00:33,133::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail) SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0438058 s, 23.4 MB/s\n'; <rc> = 0
>Thread-479::DEBUG::2014-01-20 10:00:33,473::blockSD::595::Storage.Misc.excCmd::(getReadDelay) '/bin/dd iflag=direct if=/dev/94de241c-bf5c-4630-9af3-7e31b902ae77/metadata bs=4096 count=1' (cwd None)
>Thread-479::DEBUG::2014-01-20 10:00:33,498::blockSD::595::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '1+0 records in\n1+0 records out\n4096 bytes (4.1 kB) copied, 0.000843038 s, 4.9 MB/s\n'; <rc> = 0
>[root@vostok ~]# tail -200 /var/log/vdsm/vdsm.log^C
>[root@vostok ~]# exit
>logout
>Connection to vostok closed.
>[root@buran ~]# ssh soyuz 
>root@soyuz's password: 
>Last login: Mon Jan 20 07:05:53 2014 from 10.206.3.75
>[root@soyuz ~]# tail -200 /var/log/vdsm/vdsm.log
>    if not vmDrive.blockDev or vmDrive.format != 'cow':
>AttributeError: 'Drive' object has no attribute 'format'
>Thread-87::ERROR::2014-01-20 10:01:58,535::sampling::355::vm.Vm::(collect) vmId=`84a46fd5-476e-46e8-b971-b92ac543066f`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x27b41b8>
>Traceback (most recent call last):
>  File "/usr/share/vdsm/sampling.py", line 351, in collect
>    statsFunction()
>  File "/usr/share/vdsm/sampling.py", line 226, in __call__
>    retValue = self._function(*args, **kwargs)
>  File "/usr/share/vdsm/vm.py", line 509, in _highWrite
>    if not vmDrive.blockDev or vmDrive.format != 'cow':
>AttributeError: 'Drive' object has no attribute 'format'
>Thread-81::DEBUG::2014-01-20 10:01:58,728::task::579::TaskManager.Task::(_updateState) Task=`de937148-f877-43cf-9080-75729b67822b`::moving from state init -> state preparing
>Thread-81::INFO::2014-01-20 10:01:58,730::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='f8ddd1d1-5266-493b-879b-f79c128751e2', spUUID='5849b030-626e-47cb-ad90-3ce782d831b3', imgUUID='7600f72b-94dc-442f-9b54-9200f418d14d', volUUID='ed69d504-5251-48d2-a1f2-5c8eca1e034a', options=None)
>Thread-81::INFO::2014-01-20 10:01:58,731::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '18253611008', 'apparentsize': '18253611008'}
>Thread-81::DEBUG::2014-01-20 10:01:58,733::task::1168::TaskManager.Task::(prepare) Task=`de937148-f877-43cf-9080-75729b67822b`::finished: {'truesize': '18253611008', 'apparentsize': '18253611008'}
>Thread-81::DEBUG::2014-01-20 10:01:58,733::task::579::TaskManager.Task::(_updateState) Task=`de937148-f877-43cf-9080-75729b67822b`::moving from state preparing -> state finished
>Thread-81::DEBUG::2014-01-20 10:01:58,734::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-81::DEBUG::2014-01-20 10:01:58,734::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-81::DEBUG::2014-01-20 10:01:58,734::task::974::TaskManager.Task::(_decref) Task=`de937148-f877-43cf-9080-75729b67822b`::ref 0 aborting False
>Thread-81::DEBUG::2014-01-20 10:01:58,735::task::579::TaskManager.Task::(_updateState) Task=`abbde20a-c75c-48dc-9cdf-7b5e53036898`::moving from state init -> state preparing
>Thread-81::INFO::2014-01-20 10:01:58,735::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='f8ddd1d1-5266-493b-879b-f79c128751e2', spUUID='5849b030-626e-47cb-ad90-3ce782d831b3', imgUUID='d5328e24-0227-4e34-85db-0279dd5402bf', volUUID='34bf0700-b0cf-4b44-a75a-42c6d580951a', options=None)
>Thread-81::INFO::2014-01-20 10:01:58,736::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '27917287424', 'apparentsize': '27917287424'}
>Thread-81::DEBUG::2014-01-20 10:01:58,736::task::1168::TaskManager.Task::(prepare) Task=`abbde20a-c75c-48dc-9cdf-7b5e53036898`::finished: {'truesize': '27917287424', 'apparentsize': '27917287424'}
>Thread-81::DEBUG::2014-01-20 10:01:58,736::task::579::TaskManager.Task::(_updateState) Task=`abbde20a-c75c-48dc-9cdf-7b5e53036898`::moving from state preparing -> state finished
>Thread-81::DEBUG::2014-01-20 10:01:58,736::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-81::DEBUG::2014-01-20 10:01:58,737::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-81::DEBUG::2014-01-20 10:01:58,737::task::974::TaskManager.Task::(_decref) Task=`abbde20a-c75c-48dc-9cdf-7b5e53036898`::ref 0 aborting False
>Thread-99::ERROR::2014-01-20 10:01:58,860::sampling::355::vm.Vm::(collect) vmId=`fd9bdf68-688c-48d8-8b80-02cf7bfd520f`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x27b41b8>
>Traceback (most recent call last):
>  File "/usr/share/vdsm/sampling.py", line 351, in collect
>    statsFunction()
>  File "/usr/share/vdsm/sampling.py", line 226, in __call__
>    retValue = self._function(*args, **kwargs)
>  File "/usr/share/vdsm/vm.py", line 509, in _highWrite
>    if not vmDrive.blockDev or vmDrive.format != 'cow':
>AttributeError: 'Drive' object has no attribute 'format'
>Thread-51::DEBUG::2014-01-20 10:01:59,029::libvirtconnection::108::libvirtconnection::(wrapper) Unknown libvirterror: ecode: 8 edom: 10 level: 2 message: invalid argument: invalid path /rhev/data-center/mnt/blockSD/f8ddd1d1-5266-493b-879b-f79c128751e2/images/b8da8541-9a0d-4c18-8aa8-50fc6225f18a/ff674bce-aa94-4b46-9f9d-d4182eab1e49 not assigned to domain
>Thread-51::ERROR::2014-01-20 10:01:59,029::sampling::355::vm.Vm::(collect) vmId=`493128c0-aba9-4b38-bf18-2778b910917f`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x27b41b8>
>Traceback (most recent call last):
>  File "/usr/share/vdsm/sampling.py", line 351, in collect
>    statsFunction()
>  File "/usr/share/vdsm/sampling.py", line 226, in __call__
>    retValue = self._function(*args, **kwargs)
>  File "/usr/share/vdsm/vm.py", line 513, in _highWrite
>    self._vm._dom.blockInfo(vmDrive.path, 0)
>  File "/usr/share/vdsm/vm.py", line 835, in f
>    ret = attr(*args, **kwargs)
>  File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 76, in wrapper
>    ret = f(*args, **kwargs)
>  File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1797, in blockInfo
>    if ret is None: raise libvirtError ('virDomainGetBlockInfo() failed', dom=self)
>libvirtError: invalid argument: invalid path /rhev/data-center/mnt/blockSD/f8ddd1d1-5266-493b-879b-f79c128751e2/images/b8da8541-9a0d-4c18-8aa8-50fc6225f18a/ff674bce-aa94-4b46-9f9d-d4182eab1e49 not assigned to domain
>VM Channels Listener::DEBUG::2014-01-20 10:01:59,258::vmChannels::91::vds::(_handle_timeouts) Timeout on fileno 64.
>VM Channels Listener::DEBUG::2014-01-20 10:01:59,258::vmChannels::91::vds::(_handle_timeouts) Timeout on fileno 89.
>PolicyEngine::DEBUG::2014-01-20 10:01:59,432::libvirtconnection::108::libvirtconnection::(wrapper) Unknown libvirterror: ecode: 8 edom: 10 level: 2 message: invalid argument: cannot set memory higher than max memory
>PolicyEngine::ERROR::2014-01-20 10:01:59,432::vm::4359::vm.Vm::(reportError) vmId=`ce626f90-41c4-4417-9e53-bf4066ad062d`::Set new balloon target failed
>Traceback (most recent call last):
>  File "/usr/share/vdsm/vm.py", line 4371, in setBalloonTarget
>    self._dom.setMemory(target)
>  File "/usr/share/vdsm/vm.py", line 835, in f
>    ret = attr(*args, **kwargs)
>  File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 76, in wrapper
>    ret = f(*args, **kwargs)
>  File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1410, in setMemory
>    if ret == -1: raise libvirtError ('virDomainSetMemory() failed', dom=self)
>libvirtError: invalid argument: cannot set memory higher than max memory
>Thread-118::ERROR::2014-01-20 10:01:59,539::sampling::355::vm.Vm::(collect) vmId=`f8c6190c-b722-4fcd-af17-21572151fcef`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x27b41b8>
>Traceback (most recent call last):
>  File "/usr/share/vdsm/sampling.py", line 351, in collect
>    statsFunction()
>  File "/usr/share/vdsm/sampling.py", line 226, in __call__
>    retValue = self._function(*args, **kwargs)
>  File "/usr/share/vdsm/vm.py", line 509, in _highWrite
>    if not vmDrive.blockDev or vmDrive.format != 'cow':
>AttributeError: 'Drive' object has no attribute 'format'
>Thread-136::DEBUG::2014-01-20 10:01:59,810::blockSD::595::Storage.Misc.excCmd::(getReadDelay) '/bin/dd iflag=direct if=/dev/f8ddd1d1-5266-493b-879b-f79c128751e2/metadata bs=4096 count=1' (cwd None)
>Thread-136::DEBUG::2014-01-20 10:01:59,836::blockSD::595::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '1+0 records in\n1+0 records out\n4096 bytes (4.1 kB) copied, 0.000276372 s, 14.8 MB/s\n'; <rc> = 0
>Thread-90::ERROR::2014-01-20 10:02:00,402::sampling::355::vm.Vm::(collect) vmId=`2f6dd7ce-b760-462a-abbc-e63c9390a260`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x27b41b8>
>Traceback (most recent call last):
>  File "/usr/share/vdsm/sampling.py", line 351, in collect
>    statsFunction()
>  File "/usr/share/vdsm/sampling.py", line 226, in __call__
>    retValue = self._function(*args, **kwargs)
>  File "/usr/share/vdsm/vm.py", line 509, in _highWrite
>    if not vmDrive.blockDev or vmDrive.format != 'cow':
>AttributeError: 'Drive' object has no attribute 'format'
>Thread-44::ERROR::2014-01-20 10:02:00,489::sampling::355::vm.Vm::(collect) vmId=`87c50c30-4c44-4fc3-a2ee-caea761acc03`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x27b41b8>
>Traceback (most recent call last):
>  File "/usr/share/vdsm/sampling.py", line 351, in collect
>    statsFunction()
>  File "/usr/share/vdsm/sampling.py", line 226, in __call__
>    retValue = self._function(*args, **kwargs)
>  File "/usr/share/vdsm/vm.py", line 509, in _highWrite
>    if not vmDrive.blockDev or vmDrive.format != 'cow':
>AttributeError: 'Drive' object has no attribute 'format'
>Thread-87::ERROR::2014-01-20 10:02:00,536::sampling::355::vm.Vm::(collect) vmId=`84a46fd5-476e-46e8-b971-b92ac543066f`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x27b41b8>
>Traceback (most recent call last):
>  File "/usr/share/vdsm/sampling.py", line 351, in collect
>    statsFunction()
>  File "/usr/share/vdsm/sampling.py", line 226, in __call__
>    retValue = self._function(*args, **kwargs)
>  File "/usr/share/vdsm/vm.py", line 509, in _highWrite
>    if not vmDrive.blockDev or vmDrive.format != 'cow':
>AttributeError: 'Drive' object has no attribute 'format'
>Thread-99::ERROR::2014-01-20 10:02:00,863::sampling::355::vm.Vm::(collect) vmId=`fd9bdf68-688c-48d8-8b80-02cf7bfd520f`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x27b41b8>
>Traceback (most recent call last):
>  File "/usr/share/vdsm/sampling.py", line 351, in collect
>    statsFunction()
>  File "/usr/share/vdsm/sampling.py", line 226, in __call__
>    retValue = self._function(*args, **kwargs)
>  File "/usr/share/vdsm/vm.py", line 509, in _highWrite
>    if not vmDrive.blockDev or vmDrive.format != 'cow':
>AttributeError: 'Drive' object has no attribute 'format'
>Thread-51::DEBUG::2014-01-20 10:02:01,031::libvirtconnection::108::libvirtconnection::(wrapper) Unknown libvirterror: ecode: 8 edom: 10 level: 2 message: invalid argument: invalid path /rhev/data-center/mnt/blockSD/f8ddd1d1-5266-493b-879b-f79c128751e2/images/b8da8541-9a0d-4c18-8aa8-50fc6225f18a/ff674bce-aa94-4b46-9f9d-d4182eab1e49 not assigned to domain
>Thread-51::ERROR::2014-01-20 10:02:01,032::sampling::355::vm.Vm::(collect) vmId=`493128c0-aba9-4b38-bf18-2778b910917f`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x27b41b8>
>Traceback (most recent call last):
>  File "/usr/share/vdsm/sampling.py", line 351, in collect
>    statsFunction()
>  File "/usr/share/vdsm/sampling.py", line 226, in __call__
>    retValue = self._function(*args, **kwargs)
>  File "/usr/share/vdsm/vm.py", line 513, in _highWrite
>    self._vm._dom.blockInfo(vmDrive.path, 0)
>  File "/usr/share/vdsm/vm.py", line 835, in f
>    ret = attr(*args, **kwargs)
>  File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 76, in wrapper
>    ret = f(*args, **kwargs)
>  File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1797, in blockInfo
>    if ret is None: raise libvirtError ('virDomainGetBlockInfo() failed', dom=self)
>libvirtError: invalid argument: invalid path /rhev/data-center/mnt/blockSD/f8ddd1d1-5266-493b-879b-f79c128751e2/images/b8da8541-9a0d-4c18-8aa8-50fc6225f18a/ff674bce-aa94-4b46-9f9d-d4182eab1e49 not assigned to domain
>Thread-118::ERROR::2014-01-20 10:02:01,540::sampling::355::vm.Vm::(collect) vmId=`f8c6190c-b722-4fcd-af17-21572151fcef`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x27b41b8>
>Traceback (most recent call last):
>  File "/usr/share/vdsm/sampling.py", line 351, in collect
>    statsFunction()
>  File "/usr/share/vdsm/sampling.py", line 226, in __call__
>    retValue = self._function(*args, **kwargs)
>  File "/usr/share/vdsm/vm.py", line 509, in _highWrite
>    if not vmDrive.blockDev or vmDrive.format != 'cow':
>AttributeError: 'Drive' object has no attribute 'format'
>Thread-406442::DEBUG::2014-01-20 10:02:01,929::task::579::TaskManager.Task::(_updateState) Task=`ad33ca43-fe0d-4e43-b38f-07e98f080c97`::moving from state init -> state preparing
>Thread-406442::INFO::2014-01-20 10:02:01,929::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-406442::INFO::2014-01-20 10:02:01,930::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {u'83b1867f-4aea-400e-9ce0-efbd5add4216': {'delay': '0.000234956', 'lastCheck': '6.9', 'code': 0, 'valid': True, 'version': 0}, u'94de241c-bf5c-4630-9af3-7e31b902ae77': {'delay': '0.000388197', 'lastCheck': '5.8', 'code': 0, 'valid': True, 'version': 3}, u'f3fd055b-2764-44ed-9d77-81bd58984842': {'delay': '0.000366448', 'lastCheck': '9.0', 'code': 0, 'valid': True, 'version': 3}, u'f8ddd1d1-5266-493b-879b-f79c128751e2': {'delay': '0.000276372', 'lastCheck': '2.1', 'code': 0, 'valid': True, 'version': 3}, u'50cf24a4-d1ef-4105-a9a5-b81d91339175': {'delay': '0.000511779', 'lastCheck': '4.1', 'code': 0, 'valid': True, 'version': 0}}
>Thread-406442::DEBUG::2014-01-20 10:02:01,930::task::1168::TaskManager.Task::(prepare) Task=`ad33ca43-fe0d-4e43-b38f-07e98f080c97`::finished: {u'83b1867f-4aea-400e-9ce0-efbd5add4216': {'delay': '0.000234956', 'lastCheck': '6.9', 'code': 0, 'valid': True, 'version': 0}, u'94de241c-bf5c-4630-9af3-7e31b902ae77': {'delay': '0.000388197', 'lastCheck': '5.8', 'code': 0, 'valid': True, 'version': 3}, u'f3fd055b-2764-44ed-9d77-81bd58984842': {'delay': '0.000366448', 'lastCheck': '9.0', 'code': 0, 'valid': True, 'version': 3}, u'f8ddd1d1-5266-493b-879b-f79c128751e2': {'delay': '0.000276372', 'lastCheck': '2.1', 'code': 0, 'valid': True, 'version': 3}, u'50cf24a4-d1ef-4105-a9a5-b81d91339175': {'delay': '0.000511779', 'lastCheck': '4.1', 'code': 0, 'valid': True, 'version': 0}}
>Thread-406442::DEBUG::2014-01-20 10:02:01,930::task::579::TaskManager.Task::(_updateState) Task=`ad33ca43-fe0d-4e43-b38f-07e98f080c97`::moving from state preparing -> state finished
>Thread-406442::DEBUG::2014-01-20 10:02:01,931::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-406442::DEBUG::2014-01-20 10:02:01,931::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-406442::DEBUG::2014-01-20 10:02:01,931::task::974::TaskManager.Task::(_decref) Task=`ad33ca43-fe0d-4e43-b38f-07e98f080c97`::ref 0 aborting False
>Thread-90::ERROR::2014-01-20 10:02:02,403::sampling::355::vm.Vm::(collect) vmId=`2f6dd7ce-b760-462a-abbc-e63c9390a260`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x27b41b8>
>Traceback (most recent call last):
>  File "/usr/share/vdsm/sampling.py", line 351, in collect
>    statsFunction()
>  File "/usr/share/vdsm/sampling.py", line 226, in __call__
>    retValue = self._function(*args, **kwargs)
>  File "/usr/share/vdsm/vm.py", line 509, in _highWrite
>    if not vmDrive.blockDev or vmDrive.format != 'cow':
>AttributeError: 'Drive' object has no attribute 'format'
>Thread-44::ERROR::2014-01-20 10:02:02,499::sampling::355::vm.Vm::(collect) vmId=`87c50c30-4c44-4fc3-a2ee-caea761acc03`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x27b41b8>
>Traceback (most recent call last):
>  File "/usr/share/vdsm/sampling.py", line 351, in collect
>    statsFunction()
>  File "/usr/share/vdsm/sampling.py", line 226, in __call__
>    retValue = self._function(*args, **kwargs)
>  File "/usr/share/vdsm/vm.py", line 509, in _highWrite
>    if not vmDrive.blockDev or vmDrive.format != 'cow':
>AttributeError: 'Drive' object has no attribute 'format'
>Thread-87::ERROR::2014-01-20 10:02:02,540::sampling::355::vm.Vm::(collect) vmId=`84a46fd5-476e-46e8-b971-b92ac543066f`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x27b41b8>
>Traceback (most recent call last):
>  File "/usr/share/vdsm/sampling.py", line 351, in collect
>    statsFunction()
>  File "/usr/share/vdsm/sampling.py", line 226, in __call__
>    retValue = self._function(*args, **kwargs)
>  File "/usr/share/vdsm/vm.py", line 509, in _highWrite
>    if not vmDrive.blockDev or vmDrive.format != 'cow':
>AttributeError: 'Drive' object has no attribute 'format'
>Thread-99::ERROR::2014-01-20 10:02:02,864::sampling::355::vm.Vm::(collect) vmId=`fd9bdf68-688c-48d8-8b80-02cf7bfd520f`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x27b41b8>
>Traceback (most recent call last):
>  File "/usr/share/vdsm/sampling.py", line 351, in collect
>    statsFunction()
>  File "/usr/share/vdsm/sampling.py", line 226, in __call__
>    retValue = self._function(*args, **kwargs)
>  File "/usr/share/vdsm/vm.py", line 509, in _highWrite
>    if not vmDrive.blockDev or vmDrive.format != 'cow':
>AttributeError: 'Drive' object has no attribute 'format'
>Thread-134::DEBUG::2014-01-20 10:02:02,923::blockSD::595::Storage.Misc.excCmd::(getReadDelay) '/bin/dd iflag=direct if=/dev/f3fd055b-2764-44ed-9d77-81bd58984842/metadata bs=4096 count=1' (cwd None)
>Thread-134::DEBUG::2014-01-20 10:02:02,948::blockSD::595::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '1+0 records in\n1+0 records out\n4096 bytes (4.1 kB) copied, 0.000402411 s, 10.2 MB/s\n'; <rc> = 0
>Thread-51::DEBUG::2014-01-20 10:02:03,034::libvirtconnection::108::libvirtconnection::(wrapper) Unknown libvirterror: ecode: 8 edom: 10 level: 2 message: invalid argument: invalid path /rhev/data-center/mnt/blockSD/f8ddd1d1-5266-493b-879b-f79c128751e2/images/b8da8541-9a0d-4c18-8aa8-50fc6225f18a/ff674bce-aa94-4b46-9f9d-d4182eab1e49 not assigned to domain
>Thread-51::ERROR::2014-01-20 10:02:03,035::sampling::355::vm.Vm::(collect) vmId=`493128c0-aba9-4b38-bf18-2778b910917f`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x27b41b8>
>Traceback (most recent call last):
>  File "/usr/share/vdsm/sampling.py", line 351, in collect
>    statsFunction()
>  File "/usr/share/vdsm/sampling.py", line 226, in __call__
>    retValue = self._function(*args, **kwargs)
>  File "/usr/share/vdsm/vm.py", line 513, in _highWrite
>    self._vm._dom.blockInfo(vmDrive.path, 0)
>  File "/usr/share/vdsm/vm.py", line 835, in f
>    ret = attr(*args, **kwargs)
>  File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 76, in wrapper
>    ret = f(*args, **kwargs)
>  File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1797, in blockInfo
>    if ret is None: raise libvirtError ('virDomainGetBlockInfo() failed', dom=self)
>libvirtError: invalid argument: invalid path /rhev/data-center/mnt/blockSD/f8ddd1d1-5266-493b-879b-f79c128751e2/images/b8da8541-9a0d-4c18-8aa8-50fc6225f18a/ff674bce-aa94-4b46-9f9d-d4182eab1e49 not assigned to domain
>

Actions: View

Attachments on bug 1055437: 852660