
HI , While a deploying a vm from the template ,its taking minimum 15 minutes is there any ways to solve the issues ? Thanks, Nagaraju

בתאריך 16 באוק׳ 2015 9:11 לפנה״צ, "Budur Nagaraju" <nbudoor@gmail.com> כתב:
HI ,
While a deploying a vm from the template ,its taking minimum 15 minutes
is there any ways to solve the issues ? What is the template size? storage server? network? free space on storage? logs? Nir
Thanks, Nagaraju
_______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users

Below are the details, Template size :virtual size 20GB ,actual size :4GB Storage server :Dell mounted through NFS storage capacity 2TB Free space :1.5TB There is no warn message in the engine ,let me know what logs you are expecting ? Thanks, Nagaraju On Fri, Oct 16, 2015 at 4:24 PM, Nir Soffer <nsoffer@redhat.com> wrote:
בתאריך 16 באוק׳ 2015 9:11 לפנה״צ, "Budur Nagaraju" <nbudoor@gmail.com> כתב:
HI ,
While a deploying a vm from the template ,its taking minimum 15 minutes
is there any ways to solve the issues ?
What is the template size? storage server? network? free space on storage? logs?
Nir
Thanks, Nagaraju
_______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users

בתאריך 16 באוק׳ 2015 2:10 אחה״צ, "Budur Nagaraju" <nbudoor@gmail.com> כתב:
Below are the details,
Template size :virtual size 20GB ,actual size :4GB Storage server :Dell mounted through NFS storage capacity 2TB Free space :1.5TB
There is no warn message in the engine ,let me know what logs you are
expecting ? vdsm.log showing the these 15 minutes may be useful.
Thanks, Nagaraju
On Fri, Oct 16, 2015 at 4:24 PM, Nir Soffer <nsoffer@redhat.com> wrote:
בתאריך 16 באוק׳ 2015 9:11 לפנה״צ, "Budur Nagaraju" <nbudoor@gmail.com>
כתב:
HI ,
While a deploying a vm from the template ,its taking minimum 15
minutes is there any ways to solve the issues ?
What is the template size? storage server? network? free space on storage? logs?
Nir
Thanks, Nagaraju
_______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users

Below are the logs.. tail -f /var/log/vdsm vdsm/ vdsm-reg/ [root@pbuovirt3 ~]# tail -f /var/log/vdsm/vdsm.log File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/client/client.py", line 173, in _configure_broker_conn File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/env/config.py", line 129, in get Exception: Configuration value not found: file=/etc/ovirt-hosted-engine/hosted-engine.conf, key=sdUUID Thread-178420::DEBUG::2015-10-19 03:17:31,101::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-25::DEBUG::2015-10-19 03:17:31,112::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-25::DEBUG::2015-10-19 03:17:31,123::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n342 bytes (342 B) copied, 0.000262612 s, 1.3 MB/s\n'; <rc> = 0 Thread-178421::DEBUG::2015-10-19 03:17:31,131::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-74698::DEBUG::2015-10-19 03:17:31,221::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-178422::DEBUG::2015-10-19 03:17:34,156::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-178423::DEBUG::2015-10-19 03:17:37,164::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-32442::DEBUG::2015-10-19 03:17:37,824::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_home_export__domain/1484ea07-4269-44c4-a503-fa6bf43d8bd9/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-32442::DEBUG::2015-10-19 03:17:37,834::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n347 bytes (347 B) copied, 0.000355762 s, 975 kB/s\n'; <rc> = 0 Thread-26::DEBUG::2015-10-19 03:17:39,764::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-26::DEBUG::2015-10-19 03:17:39,773::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n329 bytes (329 B) copied, 0.00037456 s, 878 kB/s\n'; <rc> = 0 Thread-178424::DEBUG::2015-10-19 03:17:40,172::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-25::DEBUG::2015-10-19 03:17:41,131::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-25::DEBUG::2015-10-19 03:17:41,141::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n342 bytes (342 B) copied, 0.000363463 s, 941 kB/s\n'; <rc> = 0 Thread-178425::DEBUG::2015-10-19 03:17:43,179::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-74187::DEBUG::2015-10-19 03:17:44,816::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-74194::DEBUG::2015-10-19 03:17:44,816::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-178426::DEBUG::2015-10-19 03:17:46,187::task::595::Storage.TaskManager.Task::(_updateState) Task=`5e671cc5-9f6d-457b-8ad1-2f41e898aa56`::moving from state init -> state preparing Thread-178426::INFO::2015-10-19 03:17:46,187::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-178426::INFO::2015-10-19 03:17:46,188::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {u'342d943d-bccb-49eb-abf5-be9f5a2afbb5': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000363463', 'lastCheck': '5.0', 'valid': True}, u'1484ea07-4269-44c4-a503-fa6bf43d8bd9': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000355762', 'lastCheck': '8.3', 'valid': True}, u'49d4a9cd-946d-41e0-a7ae-f2620f010302': {'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay': '0.00037456', 'lastCheck': '6.4', 'valid': True}} Thread-178426::DEBUG::2015-10-19 03:17:46,188::task::1191::Storage.TaskManager.Task::(prepare) Task=`5e671cc5-9f6d-457b-8ad1-2f41e898aa56`::finished: {u'342d943d-bccb-49eb-abf5-be9f5a2afbb5': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000363463', 'lastCheck': '5.0', 'valid': True}, u'1484ea07-4269-44c4-a503-fa6bf43d8bd9': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000355762', 'lastCheck': '8.3', 'valid': True}, u'49d4a9cd-946d-41e0-a7ae-f2620f010302': {'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay': '0.00037456', 'lastCheck': '6.4', 'valid': True}} Thread-178426::DEBUG::2015-10-19 03:17:46,188::task::595::Storage.TaskManager.Task::(_updateState) Task=`5e671cc5-9f6d-457b-8ad1-2f41e898aa56`::moving from state preparing -> state finished Thread-178426::DEBUG::2015-10-19 03:17:46,189::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-178426::DEBUG::2015-10-19 03:17:46,189::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-178426::DEBUG::2015-10-19 03:17:46,189::task::993::Storage.TaskManager.Task::(_decref) Task=`5e671cc5-9f6d-457b-8ad1-2f41e898aa56`::ref 0 aborting False Thread-178426::ERROR::2015-10-19 03:17:46,191::config::103::ovirt_hosted_engine_ha.env.config::(_load) Configuration file '/etc/ovirt-hosted-engine/hosted-engine.conf' not available [[Errno 2] No such file or directory: '/etc/ovirt-hosted-engine/hosted-engine.conf'] Thread-178426::ERROR::2015-10-19 03:17:46,191::config::103::ovirt_hosted_engine_ha.env.config::(_load) Configuration file '/etc/ovirt-hosted-engine/vm.conf' not available [[Errno 2] No such file or directory: '/etc/ovirt-hosted-engine/vm.conf'] Thread-178426::ERROR::2015-10-19 03:17:46,191::API::1723::vds::(_getHaInfo) failed to retrieve Hosted Engine HA info Traceback (most recent call last): File "/usr/share/vdsm/API.py", line 1703, in _getHaInfo File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/client/client.py", line 100, in get_all_stats File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/client/client.py", line 173, in _configure_broker_conn File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/env/config.py", line 129, in get Exception: Configuration value not found: file=/etc/ovirt-hosted-engine/hosted-engine.conf, key=sdUUID Thread-178426::DEBUG::2015-10-19 03:17:46,192::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-178427::DEBUG::2015-10-19 03:17:46,204::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-74698::DEBUG::2015-10-19 03:17:46,228::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-32442::DEBUG::2015-10-19 03:17:47,841::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_home_export__domain/1484ea07-4269-44c4-a503-fa6bf43d8bd9/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-32442::DEBUG::2015-10-19 03:17:47,852::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n347 bytes (347 B) copied, 0.000259381 s, 1.3 MB/s\n'; <rc> = 0 Thread-178428::DEBUG::2015-10-19 03:17:49,229::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-26::DEBUG::2015-10-19 03:17:49,780::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-26::DEBUG::2015-10-19 03:17:49,790::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n329 bytes (329 B) copied, 0.000346972 s, 948 kB/s\n'; <rc> = 0 Thread-25::DEBUG::2015-10-19 03:17:51,146::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-25::DEBUG::2015-10-19 03:17:51,155::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n342 bytes (342 B) copied, 0.000290823 s, 1.2 MB/s\n'; <rc> = 0 Thread-178429::DEBUG::2015-10-19 03:17:52,238::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-178430::DEBUG::2015-10-19 03:17:55,246::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-32442::DEBUG::2015-10-19 03:17:57,859::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_home_export__domain/1484ea07-4269-44c4-a503-fa6bf43d8bd9/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-32442::DEBUG::2015-10-19 03:17:57,868::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n347 bytes (347 B) copied, 0.000393319 s, 882 kB/s\n'; <rc> = 0 Thread-178431::DEBUG::2015-10-19 03:17:58,255::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-26::DEBUG::2015-10-19 03:17:59,796::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-26::DEBUG::2015-10-19 03:17:59,805::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n329 bytes (329 B) copied, 0.000300772 s, 1.1 MB/s\n'; <rc> = 0 Thread-74187::DEBUG::2015-10-19 03:17:59,827::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-74194::DEBUG::2015-10-19 03:17:59,827::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-25::DEBUG::2015-10-19 03:18:01,159::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-25::DEBUG::2015-10-19 03:18:01,168::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n342 bytes (342 B) copied, 0.000290265 s, 1.2 MB/s\n'; <rc> = 0 Thread-74698::DEBUG::2015-10-19 03:18:01,236::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-178432::DEBUG::2015-10-19 03:18:01,262::task::595::Storage.TaskManager.Task::(_updateState) Task=`fef96575-8a4c-486d-afc3-a346deec8ae0`::moving from state init -> state preparing Thread-178432::INFO::2015-10-19 03:18:01,262::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-178432::INFO::2015-10-19 03:18:01,262::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {u'342d943d-bccb-49eb-abf5-be9f5a2afbb5': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000290265', 'lastCheck': '0.1', 'valid': True}, u'1484ea07-4269-44c4-a503-fa6bf43d8bd9': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000393319', 'lastCheck': '3.4', 'valid': True}, u'49d4a9cd-946d-41e0-a7ae-f2620f010302': {'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay': '0.000300772', 'lastCheck': '1.5', 'valid': True}} Thread-178432::DEBUG::2015-10-19 03:18:01,263::task::1191::Storage.TaskManager.Task::(prepare) Task=`fef96575-8a4c-486d-afc3-a346deec8ae0`::finished: {u'342d943d-bccb-49eb-abf5-be9f5a2afbb5': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000290265', 'lastCheck': '0.1', 'valid': True}, u'1484ea07-4269-44c4-a503-fa6bf43d8bd9': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000393319', 'lastCheck': '3.4', 'valid': True}, u'49d4a9cd-946d-41e0-a7ae-f2620f010302': {'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay': '0.000300772', 'lastCheck': '1.5', 'valid': True}} Thread-178432::DEBUG::2015-10-19 03:18:01,263::task::595::Storage.TaskManager.Task::(_updateState) Task=`fef96575-8a4c-486d-afc3-a346deec8ae0`::moving from state preparing -> state finished Thread-178432::DEBUG::2015-10-19 03:18:01,263::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-178432::DEBUG::2015-10-19 03:18:01,263::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-178432::DEBUG::2015-10-19 03:18:01,263::task::993::Storage.TaskManager.Task::(_decref) Task=`fef96575-8a4c-486d-afc3-a346deec8ae0`::ref 0 aborting False Thread-178432::ERROR::2015-10-19 03:18:01,265::config::103::ovirt_hosted_engine_ha.env.config::(_load) Configuration file '/etc/ovirt-hosted-engine/hosted-engine.conf' not available [[Errno 2] No such file or directory: '/etc/ovirt-hosted-engine/hosted-engine.conf'] Thread-178432::ERROR::2015-10-19 03:18:01,265::config::103::ovirt_hosted_engine_ha.env.config::(_load) Configuration file '/etc/ovirt-hosted-engine/vm.conf' not available [[Errno 2] No such file or directory: '/etc/ovirt-hosted-engine/vm.conf'] Thread-178432::ERROR::2015-10-19 03:18:01,266::API::1723::vds::(_getHaInfo) failed to retrieve Hosted Engine HA info Traceback (most recent call last): File "/usr/share/vdsm/API.py", line 1703, in _getHaInfo File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/client/client.py", line 100, in get_all_stats File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/client/client.py", line 173, in _configure_broker_conn File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/env/config.py", line 129, in get Exception: Configuration value not found: file=/etc/ovirt-hosted-engine/hosted-engine.conf, key=sdUUID Thread-178432::DEBUG::2015-10-19 03:18:01,267::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-178433::DEBUG::2015-10-19 03:18:01,278::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-178434::DEBUG::2015-10-19 03:18:04,302::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-178435::DEBUG::2015-10-19 03:18:07,313::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-32442::DEBUG::2015-10-19 03:18:07,873::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_home_export__domain/1484ea07-4269-44c4-a503-fa6bf43d8bd9/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-32442::DEBUG::2015-10-19 03:18:07,882::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n347 bytes (347 B) copied, 0.000382904 s, 906 kB/s\n'; <rc> = 0 Thread-26::DEBUG::2015-10-19 03:18:09,810::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-26::DEBUG::2015-10-19 03:18:09,819::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n329 bytes (329 B) copied, 0.000372718 s, 883 kB/s\n'; <rc> = 0 Thread-178436::DEBUG::2015-10-19 03:18:10,320::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-25::DEBUG::2015-10-19 03:18:11,171::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-25::DEBUG::2015-10-19 03:18:11,180::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n342 bytes (342 B) copied, 0.000348527 s, 981 kB/s\n'; <rc> = 0 Thread-178437::DEBUG::2015-10-19 03:18:13,325::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-74187::DEBUG::2015-10-19 03:18:14,835::task::595::Storage.TaskManager.Task::(_updateState) Task=`d140d5d5-3cab-407a-8b3b-ddf2ddf16b14`::moving from state init -> state preparing Thread-74194::DEBUG::2015-10-19 03:18:14,835::task::595::Storage.TaskManager.Task::(_updateState) Task=`06eb876d-eb40-49b4-870b-f75deb9a60cb`::moving from state init -> state preparing Thread-74187::INFO::2015-10-19 03:18:14,837::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID=u'49d4a9cd-946d-41e0-a7ae-f2620f010302', spUUID=u'a24369bc-3e57-451b-a21c-422c5aa7b1e5', imgUUID=u'ae633317-e647-41df-81f5-d4c81c2c5def', volUUID=u'31d5b7b7-f0f2-4287-ad8f-666e57c0ff61', options=None) Thread-74194::INFO::2015-10-19 03:18:14,837::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID=u'49d4a9cd-946d-41e0-a7ae-f2620f010302', spUUID=u'a24369bc-3e57-451b-a21c-422c5aa7b1e5', imgUUID=u'73367293-d532-48b5-9755-b323190df47f', volUUID=u'64ebcf8d-ecd7-479f-ba9e-fff0d11a1c20', options=None) Thread-74194::INFO::2015-10-19 03:18:14,843::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '6664757248', 'apparentsize': '6664814592'} Thread-74187::INFO::2015-10-19 03:18:14,844::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '3695058944', 'apparentsize': '3695181824'} Thread-74194::DEBUG::2015-10-19 03:18:14,844::task::1191::Storage.TaskManager.Task::(prepare) Task=`06eb876d-eb40-49b4-870b-f75deb9a60cb`::finished: {'truesize': '6664757248', 'apparentsize': '6664814592'} Thread-74187::DEBUG::2015-10-19 03:18:14,845::task::1191::Storage.TaskManager.Task::(prepare) Task=`d140d5d5-3cab-407a-8b3b-ddf2ddf16b14`::finished: {'truesize': '3695058944', 'apparentsize': '3695181824'} Thread-74194::DEBUG::2015-10-19 03:18:14,845::task::595::Storage.TaskManager.Task::(_updateState) Task=`06eb876d-eb40-49b4-870b-f75deb9a60cb`::moving from state preparing -> state finished Thread-74187::DEBUG::2015-10-19 03:18:14,846::task::595::Storage.TaskManager.Task::(_updateState) Task=`d140d5d5-3cab-407a-8b3b-ddf2ddf16b14`::moving from state preparing -> state finished Thread-74194::DEBUG::2015-10-19 03:18:14,846::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-74187::DEBUG::2015-10-19 03:18:14,847::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-74194::DEBUG::2015-10-19 03:18:14,847::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-74187::DEBUG::2015-10-19 03:18:14,847::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-74194::DEBUG::2015-10-19 03:18:14,848::task::993::Storage.TaskManager.Task::(_decref) Task=`06eb876d-eb40-49b4-870b-f75deb9a60cb`::ref 0 aborting False Thread-74187::DEBUG::2015-10-19 03:18:14,848::task::993::Storage.TaskManager.Task::(_decref) Task=`d140d5d5-3cab-407a-8b3b-ddf2ddf16b14`::ref 0 aborting False Thread-74187::DEBUG::2015-10-19 03:18:14,874::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-74194::DEBUG::2015-10-19 03:18:14,874::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-74698::DEBUG::2015-10-19 03:18:16,239::task::595::Storage.TaskManager.Task::(_updateState) Task=`515b9bf4-d51b-48b8-847f-53816a01a7b7`::moving from state init -> state preparing Thread-74698::INFO::2015-10-19 03:18:16,240::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID=u'49d4a9cd-946d-41e0-a7ae-f2620f010302', spUUID=u'a24369bc-3e57-451b-a21c-422c5aa7b1e5', imgUUID=u'86f7a0dc-6ad8-4690-bae7-e3e4248bff28', volUUID=u'890ea1b5-9201-441e-8d4f-3fff58c00849', options=None) Thread-74698::INFO::2015-10-19 03:18:16,246::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '7419543552', 'apparentsize': '21474836480'} Thread-74698::DEBUG::2015-10-19 03:18:16,247::task::1191::Storage.TaskManager.Task::(prepare) Task=`515b9bf4-d51b-48b8-847f-53816a01a7b7`::finished: {'truesize': '7419543552', 'apparentsize': '21474836480'} Thread-74698::DEBUG::2015-10-19 03:18:16,248::task::595::Storage.TaskManager.Task::(_updateState) Task=`515b9bf4-d51b-48b8-847f-53816a01a7b7`::moving from state preparing -> state finished Thread-74698::DEBUG::2015-10-19 03:18:16,248::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-74698::DEBUG::2015-10-19 03:18:16,248::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-74698::DEBUG::2015-10-19 03:18:16,249::task::993::Storage.TaskManager.Task::(_decref) Task=`515b9bf4-d51b-48b8-847f-53816a01a7b7`::ref 0 aborting False Thread-74698::DEBUG::2015-10-19 03:18:16,273::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-178438::DEBUG::2015-10-19 03:18:16,332::task::595::Storage.TaskManager.Task::(_updateState) Task=`e3fb7540-0a63-49ef-a44e-05197d37b333`::moving from state init -> state preparing Thread-178438::INFO::2015-10-19 03:18:16,332::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-178438::INFO::2015-10-19 03:18:16,332::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {u'342d943d-bccb-49eb-abf5-be9f5a2afbb5': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000348527', 'lastCheck': '5.2', 'valid': True}, u'1484ea07-4269-44c4-a503-fa6bf43d8bd9': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000382904', 'lastCheck': '8.4', 'valid': True}, u'49d4a9cd-946d-41e0-a7ae-f2620f010302': {'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay': '0.000372718', 'lastCheck': '6.5', 'valid': True}} Thread-178438::DEBUG::2015-10-19 03:18:16,333::task::1191::Storage.TaskManager.Task::(prepare) Task=`e3fb7540-0a63-49ef-a44e-05197d37b333`::finished: {u'342d943d-bccb-49eb-abf5-be9f5a2afbb5': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000348527', 'lastCheck': '5.2', 'valid': True}, u'1484ea07-4269-44c4-a503-fa6bf43d8bd9': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000382904', 'lastCheck': '8.4', 'valid': True}, u'49d4a9cd-946d-41e0-a7ae-f2620f010302': {'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay': '0.000372718', 'lastCheck': '6.5', 'valid': True}} Thread-178438::DEBUG::2015-10-19 03:18:16,333::task::595::Storage.TaskManager.Task::(_updateState) Task=`e3fb7540-0a63-49ef-a44e-05197d37b333`::moving from state preparing -> state finished Thread-178438::DEBUG::2015-10-19 03:18:16,333::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-178438::DEBUG::2015-10-19 03:18:16,333::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-178438::DEBUG::2015-10-19 03:18:16,333::task::993::Storage.TaskManager.Task::(_decref) Task=`e3fb7540-0a63-49ef-a44e-05197d37b333`::ref 0 aborting False Thread-178438::ERROR::2015-10-19 03:18:16,335::config::103::ovirt_hosted_engine_ha.env.config::(_load) Configuration file '/etc/ovirt-hosted-engine/hosted-engine.conf' not available [[Errno 2] No such file or directory: '/etc/ovirt-hosted-engine/hosted-engine.conf'] Thread-178438::ERROR::2015-10-19 03:18:16,335::config::103::ovirt_hosted_engine_ha.env.config::(_load) Configuration file '/etc/ovirt-hosted-engine/vm.conf' not available [[Errno 2] No such file or directory: '/etc/ovirt-hosted-engine/vm.conf'] Thread-178438::ERROR::2015-10-19 03:18:16,335::API::1723::vds::(_getHaInfo) failed to retrieve Hosted Engine HA info Traceback (most recent call last): File "/usr/share/vdsm/API.py", line 1703, in _getHaInfo File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/client/client.py", line 100, in get_all_stats File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/client/client.py", line 173, in _configure_broker_conn File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/env/config.py", line 129, in get Exception: Configuration value not found: file=/etc/ovirt-hosted-engine/hosted-engine.conf, key=sdUUID Thread-178438::DEBUG::2015-10-19 03:18:16,336::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-178439::DEBUG::2015-10-19 03:18:16,349::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-32442::DEBUG::2015-10-19 03:18:17,886::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_home_export__domain/1484ea07-4269-44c4-a503-fa6bf43d8bd9/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-32442::DEBUG::2015-10-19 03:18:17,895::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n347 bytes (347 B) copied, 0.000457796 s, 758 kB/s\n'; <rc> = 0 Thread-178440::DEBUG::2015-10-19 03:18:19,374::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-26::DEBUG::2015-10-19 03:18:19,825::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-26::DEBUG::2015-10-19 03:18:19,834::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n329 bytes (329 B) copied, 0.00035298 s, 932 kB/s\n'; <rc> = 0 Thread-25::DEBUG::2015-10-19 03:18:21,182::domainMonitor::209::Storage.DomainMonitorThread::(_monitorDomain) Refreshing domain 342d943d-bccb-49eb-abf5-be9f5a2afbb5 Thread-178441::DEBUG::2015-10-19 03:18:21,185::__init__::298::IOProcessClient::(_run) Starting IOProcess... Thread-178442::DEBUG::2015-10-19 03:18:21,196::__init__::298::IOProcessClient::(_run) Starting IOProcess... Thread-178443::DEBUG::2015-10-19 03:18:21,208::__init__::298::IOProcessClient::(_run) Starting IOProcess... Thread-25::DEBUG::2015-10-19 03:18:21,239::fileSD::153::Storage.StorageDomain::(__init__) Reading domain in path /rhev/data-center/mnt/10.204.207.171: _var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5 Thread-25::DEBUG::2015-10-19 03:18:21,242::persistentDict::192::Storage.PersistentDict::(__init__) Created a persistent dict with FileMetadataRW backend Thread-25::DEBUG::2015-10-19 03:18:21,245::persistentDict::234::Storage.PersistentDict::(refresh) read lines (FileMetadataRW)=['CLASS=Iso', 'DESCRIPTION=ISO_DOMAIN', 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=', 'LOCKRENEWALINTERVALSEC=5', 'POOL_UUID=a24369bc-3e57-451b-a21c-422c5aa7b1e5', 'REMOTE_PATH=10.204.207.171:/var/lib/exports/iso', 'ROLE=Regular', 'SDUUID=342d943d-bccb-49eb-abf5-be9f5a2afbb5', 'TYPE=NFS', 'VERSION=0', '_SHA_CKSUM=93a3e46086203d6e02fc76fd6c8db89d8903846f'] Thread-25::DEBUG::2015-10-19 03:18:21,247::fileSD::632::Storage.StorageDomain::(imageGarbageCollector) Removing remnants of deleted images [] Thread-25::INFO::2015-10-19 03:18:21,248::sd::385::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace 342d943d-bccb-49eb-abf5-be9f5a2afbb5_imageNS already registered Thread-25::INFO::2015-10-19 03:18:21,248::sd::393::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace 342d943d-bccb-49eb-abf5-be9f5a2afbb5_volumeNS already registered Thread-25::DEBUG::2015-10-19 03:18:21,249::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-25::DEBUG::2015-10-19 03:18:21,258::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n342 bytes (342 B) copied, 0.000359113 s, 952 kB/s\n'; <rc> = 0 Thread-178444::DEBUG::2015-10-19 03:18:22,381::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-178445::DEBUG::2015-10-19 03:18:25,390::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-32442::DEBUG::2015-10-19 03:18:27,899::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_home_export__domain/1484ea07-4269-44c4-a503-fa6bf43d8bd9/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-32442::DEBUG::2015-10-19 03:18:27,908::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n347 bytes (347 B) copied, 0.000332208 s, 1.0 MB/s\n'; <rc> = 0 Thread-178446::DEBUG::2015-10-19 03:18:28,396::stompReactor::162::yajsonrpc.StompServer::(send) Sending response ^C On Fri, Oct 16, 2015 at 4:59 PM, Nir Soffer <nsoffer@redhat.com> wrote:
בתאריך 16 באוק׳ 2015 2:10 אחה״צ, "Budur Nagaraju" <nbudoor@gmail.com> כתב:
Below are the details,
Template size :virtual size 20GB ,actual size :4GB Storage server :Dell mounted through NFS storage capacity 2TB Free space :1.5TB
There is no warn message in the engine ,let me know what logs you are
expecting ?
vdsm.log showing the these 15 minutes may be useful.
Thanks, Nagaraju
On Fri, Oct 16, 2015 at 4:24 PM, Nir Soffer <nsoffer@redhat.com> wrote:
בתאריך 16 באוק׳ 2015 9:11 לפנה״צ, "Budur Nagaraju" <nbudoor@gmail.com>
כתב:
HI ,
While a deploying a vm from the template ,its taking minimum 15
minutes is there any ways to solve the issues ?
What is the template size? storage server? network? free space on storage? logs?
Nir
Thanks, Nagaraju
_______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users

We need the full vdsm logs showing the 15 minutes timeframe when you created a vm from the template. The best way to make progress is to file an ovirt bug and attach the relevant vdsm logs to the bug. Nir On Mon, Oct 19, 2015 at 6:20 AM, Budur Nagaraju <nbudoor@gmail.com> wrote:
Below are the logs..
tail -f /var/log/vdsm vdsm/ vdsm-reg/ [root@pbuovirt3 ~]# tail -f /var/log/vdsm/vdsm.log File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/client/client.py", line 173, in _configure_broker_conn File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/env/config.py", line 129, in get Exception: Configuration value not found: file=/etc/ovirt-hosted-engine/hosted-engine.conf, key=sdUUID Thread-178420::DEBUG::2015-10-19 03:17:31,101::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-25::DEBUG::2015-10-19 03:17:31,112::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-25::DEBUG::2015-10-19 03:17:31,123::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n342 bytes (342 B) copied, 0.000262612 s, 1.3 MB/s\n'; <rc> = 0 Thread-178421::DEBUG::2015-10-19 03:17:31,131::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-74698::DEBUG::2015-10-19 03:17:31,221::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-178422::DEBUG::2015-10-19 03:17:34,156::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-178423::DEBUG::2015-10-19 03:17:37,164::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-32442::DEBUG::2015-10-19 03:17:37,824::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_home_export__domain/1484ea07-4269-44c4-a503-fa6bf43d8bd9/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-32442::DEBUG::2015-10-19 03:17:37,834::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n347 bytes (347 B) copied, 0.000355762 s, 975 kB/s\n'; <rc> = 0 Thread-26::DEBUG::2015-10-19 03:17:39,764::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-26::DEBUG::2015-10-19 03:17:39,773::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n329 bytes (329 B) copied, 0.00037456 s, 878 kB/s\n'; <rc> = 0 Thread-178424::DEBUG::2015-10-19 03:17:40,172::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-25::DEBUG::2015-10-19 03:17:41,131::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-25::DEBUG::2015-10-19 03:17:41,141::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n342 bytes (342 B) copied, 0.000363463 s, 941 kB/s\n'; <rc> = 0 Thread-178425::DEBUG::2015-10-19 03:17:43,179::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-74187::DEBUG::2015-10-19 03:17:44,816::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-74194::DEBUG::2015-10-19 03:17:44,816::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-178426::DEBUG::2015-10-19 03:17:46,187::task::595::Storage.TaskManager.Task::(_updateState) Task=`5e671cc5-9f6d-457b-8ad1-2f41e898aa56`::moving from state init -> state preparing Thread-178426::INFO::2015-10-19 03:17:46,187::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-178426::INFO::2015-10-19 03:17:46,188::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {u'342d943d-bccb-49eb-abf5-be9f5a2afbb5': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000363463', 'lastCheck': '5.0', 'valid': True}, u'1484ea07-4269-44c4-a503-fa6bf43d8bd9': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000355762', 'lastCheck': '8.3', 'valid': True}, u'49d4a9cd-946d-41e0-a7ae-f2620f010302': {'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay': '0.00037456', 'lastCheck': '6.4', 'valid': True}} Thread-178426::DEBUG::2015-10-19 03:17:46,188::task::1191::Storage.TaskManager.Task::(prepare) Task=`5e671cc5-9f6d-457b-8ad1-2f41e898aa56`::finished: {u'342d943d-bccb-49eb-abf5-be9f5a2afbb5': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000363463', 'lastCheck': '5.0', 'valid': True}, u'1484ea07-4269-44c4-a503-fa6bf43d8bd9': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000355762', 'lastCheck': '8.3', 'valid': True}, u'49d4a9cd-946d-41e0-a7ae-f2620f010302': {'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay': '0.00037456', 'lastCheck': '6.4', 'valid': True}} Thread-178426::DEBUG::2015-10-19 03:17:46,188::task::595::Storage.TaskManager.Task::(_updateState) Task=`5e671cc5-9f6d-457b-8ad1-2f41e898aa56`::moving from state preparing -> state finished Thread-178426::DEBUG::2015-10-19 03:17:46,189::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-178426::DEBUG::2015-10-19 03:17:46,189::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-178426::DEBUG::2015-10-19 03:17:46,189::task::993::Storage.TaskManager.Task::(_decref) Task=`5e671cc5-9f6d-457b-8ad1-2f41e898aa56`::ref 0 aborting False Thread-178426::ERROR::2015-10-19 03:17:46,191::config::103::ovirt_hosted_engine_ha.env.config::(_load) Configuration file '/etc/ovirt-hosted-engine/hosted-engine.conf' not available [[Errno 2] No such file or directory: '/etc/ovirt-hosted-engine/hosted-engine.conf'] Thread-178426::ERROR::2015-10-19 03:17:46,191::config::103::ovirt_hosted_engine_ha.env.config::(_load) Configuration file '/etc/ovirt-hosted-engine/vm.conf' not available [[Errno 2] No such file or directory: '/etc/ovirt-hosted-engine/vm.conf'] Thread-178426::ERROR::2015-10-19 03:17:46,191::API::1723::vds::(_getHaInfo) failed to retrieve Hosted Engine HA info Traceback (most recent call last): File "/usr/share/vdsm/API.py", line 1703, in _getHaInfo File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/client/client.py", line 100, in get_all_stats File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/client/client.py", line 173, in _configure_broker_conn File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/env/config.py", line 129, in get Exception: Configuration value not found: file=/etc/ovirt-hosted-engine/hosted-engine.conf, key=sdUUID Thread-178426::DEBUG::2015-10-19 03:17:46,192::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-178427::DEBUG::2015-10-19 03:17:46,204::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-74698::DEBUG::2015-10-19 03:17:46,228::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-32442::DEBUG::2015-10-19 03:17:47,841::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_home_export__domain/1484ea07-4269-44c4-a503-fa6bf43d8bd9/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-32442::DEBUG::2015-10-19 03:17:47,852::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n347 bytes (347 B) copied, 0.000259381 s, 1.3 MB/s\n'; <rc> = 0 Thread-178428::DEBUG::2015-10-19 03:17:49,229::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-26::DEBUG::2015-10-19 03:17:49,780::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-26::DEBUG::2015-10-19 03:17:49,790::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n329 bytes (329 B) copied, 0.000346972 s, 948 kB/s\n'; <rc> = 0 Thread-25::DEBUG::2015-10-19 03:17:51,146::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-25::DEBUG::2015-10-19 03:17:51,155::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n342 bytes (342 B) copied, 0.000290823 s, 1.2 MB/s\n'; <rc> = 0 Thread-178429::DEBUG::2015-10-19 03:17:52,238::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-178430::DEBUG::2015-10-19 03:17:55,246::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-32442::DEBUG::2015-10-19 03:17:57,859::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_home_export__domain/1484ea07-4269-44c4-a503-fa6bf43d8bd9/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-32442::DEBUG::2015-10-19 03:17:57,868::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n347 bytes (347 B) copied, 0.000393319 s, 882 kB/s\n'; <rc> = 0 Thread-178431::DEBUG::2015-10-19 03:17:58,255::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-26::DEBUG::2015-10-19 03:17:59,796::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-26::DEBUG::2015-10-19 03:17:59,805::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n329 bytes (329 B) copied, 0.000300772 s, 1.1 MB/s\n'; <rc> = 0 Thread-74187::DEBUG::2015-10-19 03:17:59,827::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-74194::DEBUG::2015-10-19 03:17:59,827::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-25::DEBUG::2015-10-19 03:18:01,159::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-25::DEBUG::2015-10-19 03:18:01,168::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n342 bytes (342 B) copied, 0.000290265 s, 1.2 MB/s\n'; <rc> = 0 Thread-74698::DEBUG::2015-10-19 03:18:01,236::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-178432::DEBUG::2015-10-19 03:18:01,262::task::595::Storage.TaskManager.Task::(_updateState) Task=`fef96575-8a4c-486d-afc3-a346deec8ae0`::moving from state init -> state preparing Thread-178432::INFO::2015-10-19 03:18:01,262::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-178432::INFO::2015-10-19 03:18:01,262::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {u'342d943d-bccb-49eb-abf5-be9f5a2afbb5': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000290265', 'lastCheck': '0.1', 'valid': True}, u'1484ea07-4269-44c4-a503-fa6bf43d8bd9': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000393319', 'lastCheck': '3.4', 'valid': True}, u'49d4a9cd-946d-41e0-a7ae-f2620f010302': {'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay': '0.000300772', 'lastCheck': '1.5', 'valid': True}} Thread-178432::DEBUG::2015-10-19 03:18:01,263::task::1191::Storage.TaskManager.Task::(prepare) Task=`fef96575-8a4c-486d-afc3-a346deec8ae0`::finished: {u'342d943d-bccb-49eb-abf5-be9f5a2afbb5': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000290265', 'lastCheck': '0.1', 'valid': True}, u'1484ea07-4269-44c4-a503-fa6bf43d8bd9': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000393319', 'lastCheck': '3.4', 'valid': True}, u'49d4a9cd-946d-41e0-a7ae-f2620f010302': {'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay': '0.000300772', 'lastCheck': '1.5', 'valid': True}} Thread-178432::DEBUG::2015-10-19 03:18:01,263::task::595::Storage.TaskManager.Task::(_updateState) Task=`fef96575-8a4c-486d-afc3-a346deec8ae0`::moving from state preparing -> state finished Thread-178432::DEBUG::2015-10-19 03:18:01,263::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-178432::DEBUG::2015-10-19 03:18:01,263::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-178432::DEBUG::2015-10-19 03:18:01,263::task::993::Storage.TaskManager.Task::(_decref) Task=`fef96575-8a4c-486d-afc3-a346deec8ae0`::ref 0 aborting False Thread-178432::ERROR::2015-10-19 03:18:01,265::config::103::ovirt_hosted_engine_ha.env.config::(_load) Configuration file '/etc/ovirt-hosted-engine/hosted-engine.conf' not available [[Errno 2] No such file or directory: '/etc/ovirt-hosted-engine/hosted-engine.conf'] Thread-178432::ERROR::2015-10-19 03:18:01,265::config::103::ovirt_hosted_engine_ha.env.config::(_load) Configuration file '/etc/ovirt-hosted-engine/vm.conf' not available [[Errno 2] No such file or directory: '/etc/ovirt-hosted-engine/vm.conf'] Thread-178432::ERROR::2015-10-19 03:18:01,266::API::1723::vds::(_getHaInfo) failed to retrieve Hosted Engine HA info Traceback (most recent call last): File "/usr/share/vdsm/API.py", line 1703, in _getHaInfo File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/client/client.py", line 100, in get_all_stats File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/client/client.py", line 173, in _configure_broker_conn File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/env/config.py", line 129, in get Exception: Configuration value not found: file=/etc/ovirt-hosted-engine/hosted-engine.conf, key=sdUUID Thread-178432::DEBUG::2015-10-19 03:18:01,267::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-178433::DEBUG::2015-10-19 03:18:01,278::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-178434::DEBUG::2015-10-19 03:18:04,302::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-178435::DEBUG::2015-10-19 03:18:07,313::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-32442::DEBUG::2015-10-19 03:18:07,873::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_home_export__domain/1484ea07-4269-44c4-a503-fa6bf43d8bd9/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-32442::DEBUG::2015-10-19 03:18:07,882::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n347 bytes (347 B) copied, 0.000382904 s, 906 kB/s\n'; <rc> = 0 Thread-26::DEBUG::2015-10-19 03:18:09,810::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-26::DEBUG::2015-10-19 03:18:09,819::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n329 bytes (329 B) copied, 0.000372718 s, 883 kB/s\n'; <rc> = 0 Thread-178436::DEBUG::2015-10-19 03:18:10,320::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-25::DEBUG::2015-10-19 03:18:11,171::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-25::DEBUG::2015-10-19 03:18:11,180::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n342 bytes (342 B) copied, 0.000348527 s, 981 kB/s\n'; <rc> = 0 Thread-178437::DEBUG::2015-10-19 03:18:13,325::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-74187::DEBUG::2015-10-19 03:18:14,835::task::595::Storage.TaskManager.Task::(_updateState) Task=`d140d5d5-3cab-407a-8b3b-ddf2ddf16b14`::moving from state init -> state preparing Thread-74194::DEBUG::2015-10-19 03:18:14,835::task::595::Storage.TaskManager.Task::(_updateState) Task=`06eb876d-eb40-49b4-870b-f75deb9a60cb`::moving from state init -> state preparing Thread-74187::INFO::2015-10-19 03:18:14,837::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID=u'49d4a9cd-946d-41e0-a7ae-f2620f010302', spUUID=u'a24369bc-3e57-451b-a21c-422c5aa7b1e5', imgUUID=u'ae633317-e647-41df-81f5-d4c81c2c5def', volUUID=u'31d5b7b7-f0f2-4287-ad8f-666e57c0ff61', options=None) Thread-74194::INFO::2015-10-19 03:18:14,837::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID=u'49d4a9cd-946d-41e0-a7ae-f2620f010302', spUUID=u'a24369bc-3e57-451b-a21c-422c5aa7b1e5', imgUUID=u'73367293-d532-48b5-9755-b323190df47f', volUUID=u'64ebcf8d-ecd7-479f-ba9e-fff0d11a1c20', options=None) Thread-74194::INFO::2015-10-19 03:18:14,843::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '6664757248', 'apparentsize': '6664814592'} Thread-74187::INFO::2015-10-19 03:18:14,844::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '3695058944', 'apparentsize': '3695181824'} Thread-74194::DEBUG::2015-10-19 03:18:14,844::task::1191::Storage.TaskManager.Task::(prepare) Task=`06eb876d-eb40-49b4-870b-f75deb9a60cb`::finished: {'truesize': '6664757248', 'apparentsize': '6664814592'} Thread-74187::DEBUG::2015-10-19 03:18:14,845::task::1191::Storage.TaskManager.Task::(prepare) Task=`d140d5d5-3cab-407a-8b3b-ddf2ddf16b14`::finished: {'truesize': '3695058944', 'apparentsize': '3695181824'} Thread-74194::DEBUG::2015-10-19 03:18:14,845::task::595::Storage.TaskManager.Task::(_updateState) Task=`06eb876d-eb40-49b4-870b-f75deb9a60cb`::moving from state preparing -> state finished Thread-74187::DEBUG::2015-10-19 03:18:14,846::task::595::Storage.TaskManager.Task::(_updateState) Task=`d140d5d5-3cab-407a-8b3b-ddf2ddf16b14`::moving from state preparing -> state finished Thread-74194::DEBUG::2015-10-19 03:18:14,846::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-74187::DEBUG::2015-10-19 03:18:14,847::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-74194::DEBUG::2015-10-19 03:18:14,847::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-74187::DEBUG::2015-10-19 03:18:14,847::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-74194::DEBUG::2015-10-19 03:18:14,848::task::993::Storage.TaskManager.Task::(_decref) Task=`06eb876d-eb40-49b4-870b-f75deb9a60cb`::ref 0 aborting False Thread-74187::DEBUG::2015-10-19 03:18:14,848::task::993::Storage.TaskManager.Task::(_decref) Task=`d140d5d5-3cab-407a-8b3b-ddf2ddf16b14`::ref 0 aborting False Thread-74187::DEBUG::2015-10-19 03:18:14,874::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-74194::DEBUG::2015-10-19 03:18:14,874::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-74698::DEBUG::2015-10-19 03:18:16,239::task::595::Storage.TaskManager.Task::(_updateState) Task=`515b9bf4-d51b-48b8-847f-53816a01a7b7`::moving from state init -> state preparing Thread-74698::INFO::2015-10-19 03:18:16,240::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID=u'49d4a9cd-946d-41e0-a7ae-f2620f010302', spUUID=u'a24369bc-3e57-451b-a21c-422c5aa7b1e5', imgUUID=u'86f7a0dc-6ad8-4690-bae7-e3e4248bff28', volUUID=u'890ea1b5-9201-441e-8d4f-3fff58c00849', options=None) Thread-74698::INFO::2015-10-19 03:18:16,246::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '7419543552', 'apparentsize': '21474836480'} Thread-74698::DEBUG::2015-10-19 03:18:16,247::task::1191::Storage.TaskManager.Task::(prepare) Task=`515b9bf4-d51b-48b8-847f-53816a01a7b7`::finished: {'truesize': '7419543552', 'apparentsize': '21474836480'} Thread-74698::DEBUG::2015-10-19 03:18:16,248::task::595::Storage.TaskManager.Task::(_updateState) Task=`515b9bf4-d51b-48b8-847f-53816a01a7b7`::moving from state preparing -> state finished Thread-74698::DEBUG::2015-10-19 03:18:16,248::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-74698::DEBUG::2015-10-19 03:18:16,248::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-74698::DEBUG::2015-10-19 03:18:16,249::task::993::Storage.TaskManager.Task::(_decref) Task=`515b9bf4-d51b-48b8-847f-53816a01a7b7`::ref 0 aborting False Thread-74698::DEBUG::2015-10-19 03:18:16,273::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present Thread-178438::DEBUG::2015-10-19 03:18:16,332::task::595::Storage.TaskManager.Task::(_updateState) Task=`e3fb7540-0a63-49ef-a44e-05197d37b333`::moving from state init -> state preparing Thread-178438::INFO::2015-10-19 03:18:16,332::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-178438::INFO::2015-10-19 03:18:16,332::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {u'342d943d-bccb-49eb-abf5-be9f5a2afbb5': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000348527', 'lastCheck': '5.2', 'valid': True}, u'1484ea07-4269-44c4-a503-fa6bf43d8bd9': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000382904', 'lastCheck': '8.4', 'valid': True}, u'49d4a9cd-946d-41e0-a7ae-f2620f010302': {'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay': '0.000372718', 'lastCheck': '6.5', 'valid': True}} Thread-178438::DEBUG::2015-10-19 03:18:16,333::task::1191::Storage.TaskManager.Task::(prepare) Task=`e3fb7540-0a63-49ef-a44e-05197d37b333`::finished: {u'342d943d-bccb-49eb-abf5-be9f5a2afbb5': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000348527', 'lastCheck': '5.2', 'valid': True}, u'1484ea07-4269-44c4-a503-fa6bf43d8bd9': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000382904', 'lastCheck': '8.4', 'valid': True}, u'49d4a9cd-946d-41e0-a7ae-f2620f010302': {'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay': '0.000372718', 'lastCheck': '6.5', 'valid': True}} Thread-178438::DEBUG::2015-10-19 03:18:16,333::task::595::Storage.TaskManager.Task::(_updateState) Task=`e3fb7540-0a63-49ef-a44e-05197d37b333`::moving from state preparing -> state finished Thread-178438::DEBUG::2015-10-19 03:18:16,333::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-178438::DEBUG::2015-10-19 03:18:16,333::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-178438::DEBUG::2015-10-19 03:18:16,333::task::993::Storage.TaskManager.Task::(_decref) Task=`e3fb7540-0a63-49ef-a44e-05197d37b333`::ref 0 aborting False Thread-178438::ERROR::2015-10-19 03:18:16,335::config::103::ovirt_hosted_engine_ha.env.config::(_load) Configuration file '/etc/ovirt-hosted-engine/hosted-engine.conf' not available [[Errno 2] No such file or directory: '/etc/ovirt-hosted-engine/hosted-engine.conf'] Thread-178438::ERROR::2015-10-19 03:18:16,335::config::103::ovirt_hosted_engine_ha.env.config::(_load) Configuration file '/etc/ovirt-hosted-engine/vm.conf' not available [[Errno 2] No such file or directory: '/etc/ovirt-hosted-engine/vm.conf'] Thread-178438::ERROR::2015-10-19 03:18:16,335::API::1723::vds::(_getHaInfo) failed to retrieve Hosted Engine HA info Traceback (most recent call last): File "/usr/share/vdsm/API.py", line 1703, in _getHaInfo File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/client/client.py", line 100, in get_all_stats File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/client/client.py", line 173, in _configure_broker_conn File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/env/config.py", line 129, in get Exception: Configuration value not found: file=/etc/ovirt-hosted-engine/hosted-engine.conf, key=sdUUID Thread-178438::DEBUG::2015-10-19 03:18:16,336::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-178439::DEBUG::2015-10-19 03:18:16,349::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-32442::DEBUG::2015-10-19 03:18:17,886::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_home_export__domain/1484ea07-4269-44c4-a503-fa6bf43d8bd9/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-32442::DEBUG::2015-10-19 03:18:17,895::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n347 bytes (347 B) copied, 0.000457796 s, 758 kB/s\n'; <rc> = 0 Thread-178440::DEBUG::2015-10-19 03:18:19,374::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-26::DEBUG::2015-10-19 03:18:19,825::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-26::DEBUG::2015-10-19 03:18:19,834::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n329 bytes (329 B) copied, 0.00035298 s, 932 kB/s\n'; <rc> = 0 Thread-25::DEBUG::2015-10-19 03:18:21,182::domainMonitor::209::Storage.DomainMonitorThread::(_monitorDomain) Refreshing domain 342d943d-bccb-49eb-abf5-be9f5a2afbb5 Thread-178441::DEBUG::2015-10-19 03:18:21,185::__init__::298::IOProcessClient::(_run) Starting IOProcess... Thread-178442::DEBUG::2015-10-19 03:18:21,196::__init__::298::IOProcessClient::(_run) Starting IOProcess... Thread-178443::DEBUG::2015-10-19 03:18:21,208::__init__::298::IOProcessClient::(_run) Starting IOProcess... Thread-25::DEBUG::2015-10-19 03:18:21,239::fileSD::153::Storage.StorageDomain::(__init__) Reading domain in path /rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5 Thread-25::DEBUG::2015-10-19 03:18:21,242::persistentDict::192::Storage.PersistentDict::(__init__) Created a persistent dict with FileMetadataRW backend Thread-25::DEBUG::2015-10-19 03:18:21,245::persistentDict::234::Storage.PersistentDict::(refresh) read lines (FileMetadataRW)=['CLASS=Iso', 'DESCRIPTION=ISO_DOMAIN', 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=', 'LOCKRENEWALINTERVALSEC=5', 'POOL_UUID=a24369bc-3e57-451b-a21c-422c5aa7b1e5', 'REMOTE_PATH=10.204.207.171:/var/lib/exports/iso', 'ROLE=Regular', 'SDUUID=342d943d-bccb-49eb-abf5-be9f5a2afbb5', 'TYPE=NFS', 'VERSION=0', '_SHA_CKSUM=93a3e46086203d6e02fc76fd6c8db89d8903846f'] Thread-25::DEBUG::2015-10-19 03:18:21,247::fileSD::632::Storage.StorageDomain::(imageGarbageCollector) Removing remnants of deleted images [] Thread-25::INFO::2015-10-19 03:18:21,248::sd::385::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace 342d943d-bccb-49eb-abf5-be9f5a2afbb5_imageNS already registered Thread-25::INFO::2015-10-19 03:18:21,248::sd::393::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace 342d943d-bccb-49eb-abf5-be9f5a2afbb5_volumeNS already registered Thread-25::DEBUG::2015-10-19 03:18:21,249::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-25::DEBUG::2015-10-19 03:18:21,258::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n342 bytes (342 B) copied, 0.000359113 s, 952 kB/s\n'; <rc> = 0 Thread-178444::DEBUG::2015-10-19 03:18:22,381::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-178445::DEBUG::2015-10-19 03:18:25,390::stompReactor::162::yajsonrpc.StompServer::(send) Sending response Thread-32442::DEBUG::2015-10-19 03:18:27,899::fileSD::262::Storage.Misc.excCmd::(getReadDelay) /usr/bin/dd if=/rhev/data-center/mnt/10.204.207.171:_home_export__domain/1484ea07-4269-44c4-a503-fa6bf43d8bd9/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None) Thread-32442::DEBUG::2015-10-19 03:18:27,908::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n347 bytes (347 B) copied, 0.000332208 s, 1.0 MB/s\n'; <rc> = 0 Thread-178446::DEBUG::2015-10-19 03:18:28,396::stompReactor::162::yajsonrpc.StompServer::(send) Sending response ^C
On Fri, Oct 16, 2015 at 4:59 PM, Nir Soffer <nsoffer@redhat.com> wrote:
בתאריך 16 באוק׳ 2015 2:10 אחה״צ, "Budur Nagaraju" <nbudoor@gmail.com> כתב:
Below are the details,
Template size :virtual size 20GB ,actual size :4GB Storage server :Dell mounted through NFS storage capacity 2TB Free space :1.5TB
There is no warn message in the engine ,let me know what logs you are expecting ?
vdsm.log showing the these 15 minutes may be useful.
Thanks, Nagaraju
On Fri, Oct 16, 2015 at 4:24 PM, Nir Soffer <nsoffer@redhat.com> wrote:
בתאריך 16 באוק׳ 2015 9:11 לפנה״צ, "Budur Nagaraju" <nbudoor@gmail.com> כתב:
HI ,
While a deploying a vm from the template ,its taking minimum 15 minutes is there any ways to solve the issues ?
What is the template size? storage server? network? free space on storage? logs?
Nir
Thanks, Nagaraju
_______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users
participants (2)
-
Budur Nagaraju
-
Nir Soffer