Thread-1724::DEBUG::2015-02-26 12:00:30,962::task::993::Storage.TaskManager.Task::(_decref) Task=`717d0fa1-545c-48c6-b7ac-cb1e17f65315`::ref 0 aborting False
Thread-1486::DEBUG::2015-02-26 12:00:30,963::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1367::DEBUG::2015-02-26 12:00:30,967::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1486::DEBUG::2015-02-26 12:00:30,975::task::993::Storage.TaskManager.Task::(_decref) Task=`74b28817-1d66-454f-934d-2fee0e63a44f`::ref 0 aborting False
Thread-1367::DEBUG::2015-02-26 12:00:30,975::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1367::DEBUG::2015-02-26 12:00:30,986::task::993::Storage.TaskManager.Task::(_decref) Task=`4daedbe7-855d-491d-afbb-03afbb2c3fb6`::ref 0 aborting False
Thread-1142::DEBUG::2015-02-26 12:00:35,443::fileSD::261::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/117.18.79.72:_36Cloud__OStemplates/05be2753-83ed-4e6e-b236-4b342939a5fb/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None)
Thread-1142::DEBUG::2015-02-26 12:00:35,745::fileSD::261::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n345 bytes (345 B) copied, 0.000754595 s, 457 kB/s\n'; <rc> = 0
Thread-1141::DEBUG::2015-02-26 12:00:36,611::fileSD::261::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/glusterSD/10.10.0.14:_ds01/e732a82f-bae9-4368-8b98-dedc1c3814de/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None)
Thread-1141::DEBUG::2015-02-26 12:00:36,915::fileSD::261::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n457 bytes (457 B) copied, 0.00188971 s, 242 kB/s\n'; <rc> = 0
VM Channels Listener::DEBUG::2015-02-26 12:00:38,122::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 64.
VM Channels Listener::DEBUG::2015-02-26 12:00:38,123::vmchannels::96::vds::(_handle_timeouts) Timeout on fileno 165.
Thread-21962::DEBUG::2015-02-26 12:00:38,891::task::595::Storage.TaskManager.Task::(_updateState) Task=`3cc35ec3-08dc-4272-b9b6-d65d09f8a59c`::moving from state init -> state preparing
Thread-21962::INFO::2015-02-26 12:00:38,891::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None)
Thread-21962::INFO::2015-02-26 12:00:38,892::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'e732a82f-bae9-4368-8b98-dedc1c3814de': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.00188971', 'lastCheck': '1.9', 'valid': True}, '05be2753-83ed-4e6e-b236-4b342939a5fb': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000754595', 'lastCheck': '3.1', 'valid': True}}
Thread-21962::DEBUG::2015-02-26 12:00:38,892::task::1191::Storage.TaskManager.Task::(prepare) Task=`3cc35ec3-08dc-4272-b9b6-d65d09f8a59c`::finished: {'e732a82f-bae9-4368-8b98-dedc1c3814de': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.00188971', 'lastCheck': '1.9', 'valid': True}, '05be2753-83ed-4e6e-b236-4b342939a5fb': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000754595', 'lastCheck': '3.1', 'valid': True}}
Thread-21962::DEBUG::2015-02-26 12:00:38,892::task::595::Storage.TaskManager.Task::(_updateState) Task=`3cc35ec3-08dc-4272-b9b6-d65d09f8a59c`::moving from state preparing -> state finished
Thread-21962::DEBUG::2015-02-26 12:00:38,893::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-21962::DEBUG::2015-02-26 12:00:38,893::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-21962::DEBUG::2015-02-26 12:00:38,893::task::993::Storage.TaskManager.Task::(_decref) Task=`3cc35ec3-08dc-4272-b9b6-d65d09f8a59c`::ref 0 aborting False
Thread-1323::DEBUG::2015-02-26 12:00:39,814::task::595::Storage.TaskManager.Task::(_updateState) Task=`4de3e309-ea46-4ac5-b09f-03bae754a7b9`::moving from state init -> state preparing
Thread-1476::DEBUG::2015-02-26 12:00:39,816::task::595::Storage.TaskManager.Task::(_updateState) Task=`cf5ec94f-7abf-445b-8701-3b0bf6569a98`::moving from state init -> state preparing
Thread-1227::DEBUG::2015-02-26 12:00:39,818::task::595::Storage.TaskManager.Task::(_updateState) Task=`d09d2466-65fe-447b-8ae0-d283ec43610e`::moving from state init -> state preparing
Thread-1323::INFO::2015-02-26 12:00:39,843::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='0ecb188d-9693-4113-bc05-bca6fd2fbf38', volUUID='0582792b-dcb3-42e9-bd64-27fe1c63cd7b', options=None)
Thread-1476::INFO::2015-02-26 12:00:39,850::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='c7d148fe-3471-4974-ad55-7da3c8788fba', volUUID='6924731f-64b5-4a78-a770-04f4c1912d49', options=None)
Thread-1227::INFO::2015-02-26 12:00:39,856::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='9a046c8c-275b-440e-b751-905c6ee0a547', volUUID='8fe807a0-b766-4b5e-bbcd-ca31f68526e9', options=None)
Thread-1228::DEBUG::2015-02-26 12:00:39,907::task::595::Storage.TaskManager.Task::(_updateState) Task=`bb95acab-4145-4a08-9d51-001ee8669e56`::moving from state init -> state preparing
Thread-1228::INFO::2015-02-26 12:00:39,929::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='593a2a1c-75f8-43e6-ac87-453db7c019da', volUUID='261fec39-c203-496c-8369-6ce1815a239f', options=None)
Thread-1323::INFO::2015-02-26 12:00:40,198::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1062051840', 'apparentsize': '1073741824'}
Thread-1323::DEBUG::2015-02-26 12:00:40,277::task::1191::Storage.TaskManager.Task::(prepare) Task=`4de3e309-ea46-4ac5-b09f-03bae754a7b9`::finished: {'truesize': '1062051840', 'apparentsize': '1073741824'}
Thread-1476::INFO::2015-02-26 12:00:40,304::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1949241344', 'apparentsize': '21474836480'}
Thread-1323::DEBUG::2015-02-26 12:00:40,350::task::595::Storage.TaskManager.Task::(_updateState) Task=`4de3e309-ea46-4ac5-b09f-03bae754a7b9`::moving from state preparing -> state finished
Thread-1476::DEBUG::2015-02-26 12:00:40,394::task::1191::Storage.TaskManager.Task::(prepare) Task=`cf5ec94f-7abf-445b-8701-3b0bf6569a98`::finished: {'truesize': '1949241344', 'apparentsize': '21474836480'}
Thread-1323::DEBUG::2015-02-26 12:00:40,435::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1476::DEBUG::2015-02-26 12:00:40,479::task::595::Storage.TaskManager.Task::(_updateState) Task=`cf5ec94f-7abf-445b-8701-3b0bf6569a98`::moving from state preparing -> state finished
Thread-1323::DEBUG::2015-02-26 12:00:40,506::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1476::DEBUG::2015-02-26 12:00:40,556::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1272::DEBUG::2015-02-26 12:00:40,598::task::595::Storage.TaskManager.Task::(_updateState) Task=`ce152544-cd40-4f06-9d7a-7179a07135a1`::moving from state init -> state preparing
Thread-1476::DEBUG::2015-02-26 12:00:40,627::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1323::DEBUG::2015-02-26 12:00:40,632::task::993::Storage.TaskManager.Task::(_decref) Task=`4de3e309-ea46-4ac5-b09f-03bae754a7b9`::ref 0 aborting False
Thread-1227::INFO::2015-02-26 12:00:40,658::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1521287168', 'apparentsize': '21474836480'}
Thread-1272::INFO::2015-02-26 12:00:40,667::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='cdfa931c-20d8-4d06-831b-a4a9c34dfacc', volUUID='74c9eef6-fdc6-4d4c-9230-6ff570522677', options=None)
Thread-1476::DEBUG::2015-02-26 12:00:40,716::task::993::Storage.TaskManager.Task::(_decref) Task=`cf5ec94f-7abf-445b-8701-3b0bf6569a98`::ref 0 aborting False
Thread-1227::DEBUG::2015-02-26 12:00:40,746::task::1191::Storage.TaskManager.Task::(prepare) Task=`d09d2466-65fe-447b-8ae0-d283ec43610e`::finished: {'truesize': '1521287168', 'apparentsize': '21474836480'}
Thread-1228::INFO::2015-02-26 12:00:40,766::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '2587107328', 'apparentsize': '64424509440'}
Thread-1227::DEBUG::2015-02-26 12:00:40,799::task::595::Storage.TaskManager.Task::(_updateState) Task=`d09d2466-65fe-447b-8ae0-d283ec43610e`::moving from state preparing -> state finished
Thread-1228::DEBUG::2015-02-26 12:00:40,838::task::1191::Storage.TaskManager.Task::(prepare) Task=`bb95acab-4145-4a08-9d51-001ee8669e56`::finished: {'truesize': '2587107328', 'apparentsize': '64424509440'}
Thread-1227::DEBUG::2015-02-26 12:00:40,857::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1228::DEBUG::2015-02-26 12:00:40,903::task::595::Storage.TaskManager.Task::(_updateState) Task=`bb95acab-4145-4a08-9d51-001ee8669e56`::moving from state preparing -> state finished
Thread-1227::DEBUG::2015-02-26 12:00:40,920::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1228::DEBUG::2015-02-26 12:00:40,967::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1227::DEBUG::2015-02-26 12:00:41,019::task::993::Storage.TaskManager.Task::(_decref) Task=`d09d2466-65fe-447b-8ae0-d283ec43610e`::ref 0 aborting False
Thread-1228::DEBUG::2015-02-26 12:00:41,040::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1272::INFO::2015-02-26 12:00:41,097::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '2270900224', 'apparentsize': '21474836480'}
Thread-1228::DEBUG::2015-02-26 12:00:41,111::task::993::Storage.TaskManager.Task::(_decref) Task=`bb95acab-4145-4a08-9d51-001ee8669e56`::ref 0 aborting False
Thread-1272::DEBUG::2015-02-26 12:00:41,145::task::1191::Storage.TaskManager.Task::(prepare) Task=`ce152544-cd40-4f06-9d7a-7179a07135a1`::finished: {'truesize': '2270900224', 'apparentsize': '21474836480'}
Thread-1272::DEBUG::2015-02-26 12:00:41,169::task::595::Storage.TaskManager.Task::(_updateState) Task=`ce152544-cd40-4f06-9d7a-7179a07135a1`::moving from state preparing -> state finished
Thread-1272::DEBUG::2015-02-26 12:00:41,192::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1272::DEBUG::2015-02-26 12:00:41,218::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1272::DEBUG::2015-02-26 12:00:41,241::task::993::Storage.TaskManager.Task::(_decref) Task=`ce152544-cd40-4f06-9d7a-7179a07135a1`::ref 0 aborting False
Thread-1142::DEBUG::2015-02-26 12:00:45,761::fileSD::261::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/117.18.79.72:_36Cloud__OStemplates/05be2753-83ed-4e6e-b236-4b342939a5fb/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None)
Thread-1142::DEBUG::2015-02-26 12:00:46,287::fileSD::261::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n345 bytes (345 B) copied, 0.000730037 s, 473 kB/s\n'; <rc> = 0
Thread-1141::DEBUG::2015-02-26 12:00:47,214::fileSD::261::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/glusterSD/10.10.0.14:_ds01/e732a82f-bae9-4368-8b98-dedc1c3814de/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None)
Thread-1141::DEBUG::2015-02-26 12:00:47,620::fileSD::261::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n457 bytes (457 B) copied, 0.000609714 s, 750 kB/s\n'; <rc> = 0
Thread-1735::DEBUG::2015-02-26 12:00:53,043::task::595::Storage.TaskManager.Task::(_updateState) Task=`8acb9b59-50df-44c0-a402-7c3e8a21a974`::moving from state init -> state preparing
Thread-1207::DEBUG::2015-02-26 12:00:53,045::task::595::Storage.TaskManager.Task::(_updateState) Task=`335f1909-abd1-417f-a68b-06c773692e6b`::moving from state init -> state preparing
Thread-1657::DEBUG::2015-02-26 12:00:53,061::task::595::Storage.TaskManager.Task::(_updateState) Task=`e937884a-ae7c-478f-9584-0f563e5d70e0`::moving from state init -> state preparing
Thread-1768::DEBUG::2015-02-26 12:00:53,065::task::595::Storage.TaskManager.Task::(_updateState) Task=`7ddb5073-0e2b-49ca-80ca-ad26d1f145ba`::moving from state init -> state preparing
Thread-1735::INFO::2015-02-26 12:00:53,077::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='58c15d54-1249-4ada-98e3-8d2626335a76', volUUID='0651eaa6-5733-4039-8e05-8846f44966ee', options=None)
Thread-1207::INFO::2015-02-26 12:00:53,087::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='608a5242-bab8-4b7d-8420-98b56fb5e814', volUUID='1c318dff-3cd5-458b-a50d-0207c1e18487', options=None)
Thread-1657::INFO::2015-02-26 12:00:53,097::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='efc7437c-5efa-4818-94b7-f7ee9872b7df', volUUID='ce43b19c-5f84-47cd-95b9-d1ae54de892b', options=None)
Thread-1768::INFO::2015-02-26 12:00:53,102::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='4f7666e4-f526-4603-98be-9974a9aedd0e', volUUID='98383492-b95d-40bf-b696-9d45f9cbf38e', options=None)
Thread-1735::INFO::2015-02-26 12:00:53,197::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1309057024', 'apparentsize': '21474836480'}
Thread-1768::INFO::2015-02-26 12:00:53,210::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1855746048', 'apparentsize': '21474836480'}
Thread-1735::DEBUG::2015-02-26 12:00:53,210::task::1191::Storage.TaskManager.Task::(prepare) Task=`8acb9b59-50df-44c0-a402-7c3e8a21a974`::finished: {'truesize': '1309057024', 'apparentsize': '21474836480'}
Thread-1657::INFO::2015-02-26 12:00:53,220::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1054064640', 'apparentsize': '1073741824'}
Thread-1735::DEBUG::2015-02-26 12:00:53,220::task::595::Storage.TaskManager.Task::(_updateState) Task=`8acb9b59-50df-44c0-a402-7c3e8a21a974`::moving from state preparing -> state finished
Thread-1768::DEBUG::2015-02-26 12:00:53,221::task::1191::Storage.TaskManager.Task::(prepare) Task=`7ddb5073-0e2b-49ca-80ca-ad26d1f145ba`::finished: {'truesize': '1855746048', 'apparentsize': '21474836480'}
Thread-1207::INFO::2015-02-26 12:00:53,232::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1054064640', 'apparentsize': '1073741824'}
Thread-1657::DEBUG::2015-02-26 12:00:53,233::task::1191::Storage.TaskManager.Task::(prepare) Task=`e937884a-ae7c-478f-9584-0f563e5d70e0`::finished: {'truesize': '1054064640', 'apparentsize': '1073741824'}
Thread-1735::DEBUG::2015-02-26 12:00:53,232::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1768::DEBUG::2015-02-26 12:00:53,236::task::595::Storage.TaskManager.Task::(_updateState) Task=`7ddb5073-0e2b-49ca-80ca-ad26d1f145ba`::moving from state preparing -> state finished
Thread-1207::DEBUG::2015-02-26 12:00:53,243::task::1191::Storage.TaskManager.Task::(prepare) Task=`335f1909-abd1-417f-a68b-06c773692e6b`::finished: {'truesize': '1054064640', 'apparentsize': '1073741824'}
Thread-1657::DEBUG::2015-02-26 12:00:53,243::task::595::Storage.TaskManager.Task::(_updateState) Task=`e937884a-ae7c-478f-9584-0f563e5d70e0`::moving from state preparing -> state finished
Thread-1735::DEBUG::2015-02-26 12:00:53,247::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1768::DEBUG::2015-02-26 12:00:53,252::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1207::DEBUG::2015-02-26 12:00:53,255::task::595::Storage.TaskManager.Task::(_updateState) Task=`335f1909-abd1-417f-a68b-06c773692e6b`::moving from state preparing -> state finished
Thread-1657::DEBUG::2015-02-26 12:00:53,257::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1735::DEBUG::2015-02-26 12:00:53,262::task::993::Storage.TaskManager.Task::(_decref) Task=`8acb9b59-50df-44c0-a402-7c3e8a21a974`::ref 0 aborting False
Thread-1768::DEBUG::2015-02-26 12:00:53,263::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1207::DEBUG::2015-02-26 12:00:53,267::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1657::DEBUG::2015-02-26 12:00:53,270::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1768::DEBUG::2015-02-26 12:00:53,279::task::993::Storage.TaskManager.Task::(_decref) Task=`7ddb5073-0e2b-49ca-80ca-ad26d1f145ba`::ref 0 aborting False
Thread-1207::DEBUG::2015-02-26 12:00:53,279::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1657::DEBUG::2015-02-26 12:00:53,284::task::993::Storage.TaskManager.Task::(_decref) Task=`e937884a-ae7c-478f-9584-0f563e5d70e0`::ref 0 aborting False
Thread-1207::DEBUG::2015-02-26 12:00:53,293::task::993::Storage.TaskManager.Task::(_decref) Task=`335f1909-abd1-417f-a68b-06c773692e6b`::ref 0 aborting False
Thread-1316::DEBUG::2015-02-26 12:00:55,698::task::595::Storage.TaskManager.Task::(_updateState) Task=`5ac32e55-d42e-4331-8be8-8c07d0f4fa41`::moving from state init -> state preparing
Thread-1769::DEBUG::2015-02-26 12:00:55,710::task::595::Storage.TaskManager.Task::(_updateState) Task=`951c41f6-ddc2-4e38-87fd-831e869ef72b`::moving from state init -> state preparing
Thread-1316::INFO::2015-02-26 12:00:55,710::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='9c3bf1c1-d63e-4706-a91d-ed538743cc78', volUUID='88ab7ecc-4672-4ce3-8d65-210544709bbc', options=None)
Thread-1769::INFO::2015-02-26 12:00:55,713::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='eddcaf68-6dc9-4db8-bb23-1a0a158920e3', volUUID='da6e9f92-cd2b-4c6f-a783-31e5a05e6d70', options=None)
Thread-1316::INFO::2015-02-26 12:00:55,774::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '2224254976', 'apparentsize': '42949672960'}
Thread-1316::DEBUG::2015-02-26 12:00:55,775::task::1191::Storage.TaskManager.Task::(prepare) Task=`5ac32e55-d42e-4331-8be8-8c07d0f4fa41`::finished: {'truesize': '2224254976', 'apparentsize': '42949672960'}
Thread-1316::DEBUG::2015-02-26 12:00:55,775::task::595::Storage.TaskManager.Task::(_updateState) Task=`5ac32e55-d42e-4331-8be8-8c07d0f4fa41`::moving from state preparing -> state finished
Thread-1316::DEBUG::2015-02-26 12:00:55,775::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1316::DEBUG::2015-02-26 12:00:55,775::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1316::DEBUG::2015-02-26 12:00:55,777::task::993::Storage.TaskManager.Task::(_decref) Task=`5ac32e55-d42e-4331-8be8-8c07d0f4fa41`::ref 0 aborting False
Thread-1769::INFO::2015-02-26 12:00:55,778::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '2065268736', 'apparentsize': '21474836480'}
Thread-1769::DEBUG::2015-02-26 12:00:55,779::task::1191::Storage.TaskManager.Task::(prepare) Task=`951c41f6-ddc2-4e38-87fd-831e869ef72b`::finished: {'truesize': '2065268736', 'apparentsize': '21474836480'}
Thread-1769::DEBUG::2015-02-26 12:00:55,779::task::595::Storage.TaskManager.Task::(_updateState) Task=`951c41f6-ddc2-4e38-87fd-831e869ef72b`::moving from state preparing -> state finished
Thread-1769::DEBUG::2015-02-26 12:00:55,779::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1769::DEBUG::2015-02-26 12:00:55,779::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1769::DEBUG::2015-02-26 12:00:55,779::task::993::Storage.TaskManager.Task::(_decref) Task=`951c41f6-ddc2-4e38-87fd-831e869ef72b`::ref 0 aborting False
Thread-1142::DEBUG::2015-02-26 12:00:56,641::fileSD::261::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/117.18.79.72:_36Cloud__OStemplates/05be2753-83ed-4e6e-b236-4b342939a5fb/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None)
Thread-1142::DEBUG::2015-02-26 12:00:56,904::fileSD::261::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n345 bytes (345 B) copied, 0.000735335 s, 469 kB/s\n'; <rc> = 0
Thread-1475::DEBUG::2015-02-26 12:00:57,073::task::595::Storage.TaskManager.Task::(_updateState) Task=`4b8d1674-64cf-40d5-8f9c-2fef9cd045d4`::moving from state init -> state preparing
Thread-1475::INFO::2015-02-26 12:00:57,075::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='e0a9412d-3fef-419f-81ad-219be78e3bc2', volUUID='71b3875e-7fac-4bf2-90ca-59764dc1e678', options=None)
Thread-1475::INFO::2015-02-26 12:00:57,100::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '1388470272', 'apparentsize': '21474836480'}
Thread-1475::DEBUG::2015-02-26 12:00:57,101::task::1191::Storage.TaskManager.Task::(prepare) Task=`4b8d1674-64cf-40d5-8f9c-2fef9cd045d4`::finished: {'truesize': '1388470272', 'apparentsize': '21474836480'}
Thread-1475::DEBUG::2015-02-26 12:00:57,101::task::595::Storage.TaskManager.Task::(_updateState) Task=`4b8d1674-64cf-40d5-8f9c-2fef9cd045d4`::moving from state preparing -> state finished
Thread-1475::DEBUG::2015-02-26 12:00:57,101::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1475::DEBUG::2015-02-26 12:00:57,102::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1475::DEBUG::2015-02-26 12:00:57,102::task::993::Storage.TaskManager.Task::(_decref) Task=`4b8d1674-64cf-40d5-8f9c-2fef9cd045d4`::ref 0 aborting False
Thread-1141::DEBUG::2015-02-26 12:00:58,067::fileSD::261::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/glusterSD/10.10.0.14:_ds01/e732a82f-bae9-4368-8b98-dedc1c3814de/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None)
Thread-1141::DEBUG::2015-02-26 12:00:58,611::fileSD::261::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n457 bytes (457 B) copied, 0.000614678 s, 743 kB/s\n'; <rc> = 0
Thread-1208::DEBUG::2015-02-26 12:00:59,290::task::595::Storage.TaskManager.Task::(_updateState) Task=`4485d572-ca37-4d1d-bcc1-b2d52972d07a`::moving from state init -> state preparing
Thread-1233::DEBUG::2015-02-26 12:00:59,297::task::595::Storage.TaskManager.Task::(_updateState) Task=`f7bafdcd-4757-4927-9af3-84776ef8b946`::moving from state init -> state preparing
Thread-1208::INFO::2015-02-26 12:00:59,383::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='51953634-9ec5-44c9-9ab5-e4b5f98e09c4', volUUID='1587e47a-be14-4614-a201-b9bdc157b1bc', options=None)
Thread-1233::INFO::2015-02-26 12:00:59,408::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='e732a82f-bae9-4368-8b98-dedc1c3814de', spUUID='00000002-0002-0002-0002-000000000145', imgUUID='a4b1b2d5-4158-4d36-a8a0-41ea6fba6dca', volUUID='8f36def4-b6cd-4b10-aaf0-2a0c5b2757cc', options=None)
Thread-1208::INFO::2015-02-26 12:00:59,685::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '2129100800', 'apparentsize': '21474836480'}
Thread-1208::DEBUG::2015-02-26 12:00:59,726::task::1191::Storage.TaskManager.Task::(prepare) Task=`4485d572-ca37-4d1d-bcc1-b2d52972d07a`::finished: {'truesize': '2129100800', 'apparentsize': '21474836480'}
Thread-1233::INFO::2015-02-26 12:00:59,730::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '2752720896', 'apparentsize': '21474836480'}
Thread-1208::DEBUG::2015-02-26 12:00:59,754::task::595::Storage.TaskManager.Task::(_updateState) Task=`4485d572-ca37-4d1d-bcc1-b2d52972d07a`::moving from state preparing -> state finished
Thread-1233::DEBUG::2015-02-26 12:00:59,769::task::1191::Storage.TaskManager.Task::(prepare) Task=`f7bafdcd-4757-4927-9af3-84776ef8b946`::finished: {'truesize': '2752720896', 'apparentsize': '21474836480'}
Thread-1208::DEBUG::2015-02-26 12:00:59,777::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1233::DEBUG::2015-02-26 12:00:59,795::task::595::Storage.TaskManager.Task::(_updateState) Task=`f7bafdcd-4757-4927-9af3-84776ef8b946`::moving from state preparing -> state finished
Thread-1208::DEBUG::2015-02-26 12:00:59,802::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1233::DEBUG::2015-02-26 12:00:59,813::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1208::DEBUG::2015-02-26 12:00:59,827::task::993::Storage.TaskManager.Task::(_decref) Task=`4485d572-ca37-4d1d-bcc1-b2d52972d07a`::ref 0 aborting False
Thread-1233::DEBUG::2015-02-26 12:00:59,844::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1233::DEBUG::2015-02-26 12:00:59,872::task::993::Storage.TaskManager.Task::(_decref) Task=`f7bafdcd-4757-4927-9af3-84776ef8b946`::ref 0 aborting False
Thread-21962::DEBUG::2015-02-26 12:00:59,937::task::595::Storage.TaskManager.Task::(_updateState) Task=`6518ec2a-2d8c-4235-875b-7a8a15ddbd49`::moving from state init -> state preparing
Thread-21962::INFO::2015-02-26 12:00:59,945::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None)
Thread-21962::INFO::2015-02-26 12:00:59,956::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'e732a82f-bae9-4368-8b98-dedc1c3814de': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000614678', 'lastCheck': '0.6', 'valid': True}, '05be2753-83ed-4e6e-b236-4b342939a5fb': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000735335', 'lastCheck': '3.0', 'valid': True}}
Thread-21962::DEBUG::2015-02-26 12:00:59,962::task::1191::Storage.TaskManager.Task::(prepare) Task=`6518ec2a-2d8c-4235-875b-7a8a15ddbd49`::finished: {'e732a82f-bae9-4368-8b98-dedc1c3814de': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000614678', 'lastCheck': '0.6', 'valid': True}, '05be2753-83ed-4e6e-b236-4b342939a5fb': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000735335', 'lastCheck': '3.0', 'valid': True}}
Thread-21962::DEBUG::2015-02-26 12:00:59,967::task::595::Storage.TaskManager.Task::(_updateState) Task=`6518ec2a-2d8c-4235-875b-7a8a15ddbd49`::moving from state preparing -> state finished
Thread-21962::DEBUG::2015-02-26 12:00:59,972::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-21962::DEBUG::2015-02-26 12:00:59,977::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-21962::DEBUG::2015-02-26 12:00:59,986::task::993::Storage.TaskManager.Task::(_decref) Task=`6518ec2a-2d8c-4235-875b-7a8a15ddbd49`::ref 0 aborting False