Add operation ID for remote calls

The operation ID is a random string which can be added in the SOAP
headers of the remote request. vCenter and ESX will append this opID to
every log message associated with the remote request. This allows
administrators to correlate log messages for particular operation across
different systems (OpenStack -> vCenter -> ESX).

There is also addition keyword argument 'skip_op_id' which allows
callers to disable logging the opID if set to True.

Example for correlating logs for CreateVM_Task on devstack, vCenter and
ESX: http://paste.openstack.org/show/592614/

Change-Id: I75cb71c7c58b4ee9cd36fc977eb2a18a911f161f
This commit is contained in:
Radoslav Gerganov 2016-12-16 13:47:32 +02:00
parent 0c3a089d10
commit 6a63362919
8 changed files with 91 additions and 20 deletions

View File

@ -140,7 +140,7 @@ class VMwareAPISession(object):
api_retry_count, task_poll_interval, scheme='https',
create_session=True, wsdl_loc=None, pbm_wsdl_loc=None,
port=443, cacert=None, insecure=True, pool_size=10,
connection_timeout=None):
connection_timeout=None, op_id_prefix='oslo.vmware'):
"""Initializes the API session with given parameters.
:param host: ESX/VC server IP address or host name
@ -164,6 +164,7 @@ class VMwareAPISession(object):
connection pool
:param connection_timeout: Maximum time in seconds to wait for peer to
respond.
:param op_id_prefix: String prefix for the operation ID.
:raises: VimException, VimFaultException, VimAttributeException,
VimSessionOverLoadException
"""
@ -184,6 +185,7 @@ class VMwareAPISession(object):
self._insecure = insecure
self._pool_size = pool_size
self._connection_timeout = connection_timeout
self._op_id_prefix = op_id_prefix
if create_session:
self._create_session()
@ -202,7 +204,8 @@ class VMwareAPISession(object):
cacert=self._cacert,
insecure=self._insecure,
pool_maxsize=self._pool_size,
connection_timeout=self._connection_timeout)
connection_timeout=self._connection_timeout,
op_id_prefix=self._op_id_prefix)
return self._vim
@property
@ -215,7 +218,8 @@ class VMwareAPISession(object):
cacert=self._cacert,
insecure=self._insecure,
pool_maxsize=self._pool_size,
connection_timeout=self._connection_timeout)
connection_timeout=self._connection_timeout,
op_id_prefix=self._op_id_prefix)
if self._session_id:
# To handle the case where pbm property is accessed after
# session creation. If pbm property is accessed before session
@ -401,13 +405,15 @@ class VMwareAPISession(object):
:param task: managed object reference of the task
"""
LOG.debug("Invoking VIM API to read info of task: %s.", task)
try:
# we poll tasks too often, so skip logging the opID as it generates
# too much noise in the logs
task_info = self.invoke_api(vim_util,
'get_object_property',
self.vim,
task,
'info')
'info',
skip_op_id=True)
except exceptions.VimException:
with excutils.save_and_reraise_exception():
LOG.exception(_LE("Error occurred while reading info of "

View File

@ -42,7 +42,7 @@ class Pbm(service.Service):
def __init__(self, protocol='https', host='localhost', port=443,
wsdl_url=None, cacert=None, insecure=True, pool_maxsize=10,
connection_timeout=None):
connection_timeout=None, op_id_prefix='oslo.vmware'):
"""Constructs a PBM service client object.
:param protocol: http or https
@ -55,13 +55,15 @@ class Pbm(service.Service):
used only if cacert is not specified
:param pool_maxsize: Maximum number of connections in http
connection pool
:param op_id_prefix: String prefix for the operation ID.
:param connection_timeout: Maximum time in seconds to wait for peer to
respond.
"""
base_url = service.Service.build_base_url(protocol, host, port)
soap_url = base_url + '/pbm'
super(Pbm, self).__init__(wsdl_url, soap_url, cacert, insecure,
pool_maxsize, connection_timeout)
pool_maxsize, connection_timeout,
op_id_prefix)
def set_soap_cookie(self, cookie):
"""Set the specified vCenter session cookie in the SOAP header

View File

@ -22,6 +22,7 @@ import os
import netaddr
from oslo_utils import timeutils
from oslo_utils import uuidutils
import requests
import six
import six.moves.http_client as httplib
@ -29,6 +30,7 @@ import suds
from suds import cache
from suds import client
from suds import plugin
import suds.sax.element as element
from suds import transport
from oslo_vmware._i18n import _
@ -70,6 +72,7 @@ class ServiceMessagePlugin(plugin.MessagePlugin):
# Suds builds the entire request object based on the WSDL schema.
# VI SDK throws server errors if optional SOAP nodes are sent
# without values; e.g., <test/> as opposed to <test>test</test>.
context.envelope.prune()
context.envelope.walk(self.add_attribute_for_value)
@ -194,9 +197,10 @@ class Service(object):
def __init__(self, wsdl_url=None, soap_url=None,
cacert=None, insecure=True, pool_maxsize=10,
connection_timeout=None):
connection_timeout=None, op_id_prefix='oslo.vmware'):
self.wsdl_url = wsdl_url
self.soap_url = soap_url
self.op_id_prefix = op_id_prefix
LOG.debug("Creating suds client with soap_url='%s' and wsdl_url='%s'",
self.soap_url, self.wsdl_url)
transport = RequestsTransport(cacert=cacert,
@ -260,6 +264,17 @@ class Service(object):
fault_string,
details=details)
def _add_operation_id(self, op_id):
"""Add operation ID for the next remote call to vCenter.
The operation ID is a random string which allows to correlate log
messages across different systems (OpenStack, vCenter, ESX).
"""
headers = [element.Element('operationID').setText(op_id)]
if self.client.options.soapheaders is not None:
headers.append(self.client.options.soapheaders)
self.client.set_options(soapheaders=headers)
@property
def service_content(self):
if self._service_content is None:
@ -297,6 +312,18 @@ class Service(object):
managed_object)
if managed_object is None:
return
skip_op_id = kwargs.pop('skip_op_id', False)
if not skip_op_id:
# Generate opID. It will appear in vCenter and ESX logs for
# this particular remote call.
op_id = '%s-%s' % (self.op_id_prefix,
uuidutils.generate_uuid())
LOG.debug('Invoking %s.%s with opID=%s',
managed_object._type,
attr_name,
op_id)
self._add_operation_id(op_id)
request = getattr(self.client.service, attr_name)
response = request(managed_object, **kwargs)
if (attr_name.lower() == 'retrievepropertiesex'):

View File

@ -137,7 +137,8 @@ class VMwareAPISessionTest(base.TestCase):
cacert=self.cert_mock,
insecure=False,
pool_maxsize=VMwareAPISessionTest.POOL_SIZE,
connection_timeout=None)
connection_timeout=None,
op_id_prefix='oslo.vmware')
@mock.patch.object(pbm, 'Pbm')
def test_pbm(self, pbm_mock):
@ -412,7 +413,8 @@ class VMwareAPISessionTest(base.TestCase):
api_session.invoke_api.assert_called_with(vim_util,
'get_object_property',
api_session.vim, task,
'info')
'info',
skip_op_id=True)
self.assertEqual(task_info_list_size,
api_session.invoke_api.call_count)
@ -437,7 +439,8 @@ class VMwareAPISessionTest(base.TestCase):
api_session.invoke_api.assert_called_with(vim_util,
'get_object_property',
api_session.vim, task,
'info')
'info',
skip_op_id=True)
self.assertEqual(task_info_list_size,
api_session.invoke_api.call_count)
@ -453,7 +456,8 @@ class VMwareAPISessionTest(base.TestCase):
api_session.invoke_api.assert_called_once_with(vim_util,
'get_object_property',
api_session.vim, task,
'info')
'info',
skip_op_id=True)
def test_wait_for_lease_ready(self):
api_session = self._create_api_session(True)

View File

@ -374,6 +374,31 @@ class ServiceTest(base.TestCase):
svc_obj.client.options.transport.cookiejar = [cookie]
self.assertIsNone(svc_obj.get_http_cookie())
def test_add_operation_id(self):
def fake_set_options(*args, **kwargs):
headers = kwargs['soapheaders']
self.assertEqual(1, len(headers))
txt = headers[0].getText()
self.assertEqual('fira-12345', txt)
svc_obj = service.Service()
svc_obj.client.options.soapheaders = None
setattr(svc_obj.client, 'set_options', fake_set_options)
svc_obj._add_operation_id('fira-12345')
def test_add_operation_id_with_existing_header(self):
def fake_set_options(*args, **kwargs):
headers = kwargs['soapheaders']
self.assertEqual(2, len(headers))
txt = headers[0].getText()
self.assertEqual('fira-12345', txt)
self.assertEqual('vc-session-cookie', headers[1])
svc_obj = service.Service()
svc_obj.client.options.soapheaders = 'vc-session-cookie'
setattr(svc_obj.client, 'set_options', fake_set_options)
svc_obj._add_operation_id('fira-12345')
class MemoryCacheTest(base.TestCase):
"""Test class for MemoryCache."""

View File

@ -222,7 +222,8 @@ class VimUtilTest(base.TestCase):
moref._type = "VirtualMachine"
retrieve_result = mock.Mock()
def vim_RetrievePropertiesEx_side_effect(pc, specSet, options):
def vim_RetrievePropertiesEx_side_effect(pc, specSet, options,
skip_op_id=False):
self.assertTrue(pc is vim.service_content.propertyCollector)
self.assertEqual(1, options.maxObjects)
@ -361,7 +362,7 @@ class VimUtilTest(base.TestCase):
val = vim_util.get_object_property(vim, moref, property_name)
self.assertEqual(prop.val, val)
get_object_properties.assert_called_once_with(
vim, moref, [property_name])
vim, moref, [property_name], skip_op_id=False)
def test_find_extension(self):
vim = mock.Mock()

View File

@ -21,7 +21,7 @@ class Vim(service.Service):
def __init__(self, protocol='https', host='localhost', port=None,
wsdl_url=None, cacert=None, insecure=True, pool_maxsize=10,
connection_timeout=None):
connection_timeout=None, op_id_prefix='oslo.vmware'):
"""Constructs a VIM service client object.
:param protocol: http or https
@ -36,6 +36,7 @@ class Vim(service.Service):
connection pool
:param connection_timeout: Maximum time in seconds to wait for peer to
respond.
:param op_id_prefix: String prefix for the operation ID.
:raises: VimException, VimFaultException, VimAttributeException,
VimSessionOverLoadException, VimConnectionException
"""
@ -44,7 +45,8 @@ class Vim(service.Service):
if wsdl_url is None:
wsdl_url = soap_url + '/vimService.wsdl'
super(Vim, self).__init__(wsdl_url, soap_url, cacert, insecure,
pool_maxsize, connection_timeout)
pool_maxsize, connection_timeout,
op_id_prefix)
def retrieve_service_content(self):
return self.RetrieveServiceContent(service.SERVICE_INSTANCE)

View File

@ -285,13 +285,14 @@ def get_objects(vim, type_, max_objects, properties_to_collect=None,
options=options)
def get_object_properties(vim, moref, properties_to_collect):
def get_object_properties(vim, moref, properties_to_collect, skip_op_id=False):
"""Get properties of the given managed object.
:param vim: Vim object
:param moref: managed object reference
:param properties_to_collect: names of the managed object properties to be
collected
:param skip_op_id: whether to skip putting opID in the request
:returns: properties of the given managed object
:raises: VimException, VimFaultException, VimAttributeException,
VimSessionOverLoadException, VimConnectionException
@ -317,7 +318,8 @@ def get_object_properties(vim, moref, properties_to_collect):
retrieve_result = vim.RetrievePropertiesEx(
vim.service_content.propertyCollector,
specSet=[property_filter_spec],
options=options)
options=options,
skip_op_id=skip_op_id)
cancel_retrieval(vim, retrieve_result)
return retrieve_result.objects
@ -422,17 +424,19 @@ class WithRetrieval(object):
self.vim, self.retrieve_result)
def get_object_property(vim, moref, property_name):
def get_object_property(vim, moref, property_name, skip_op_id=False):
"""Get property of the given managed object.
:param vim: Vim object
:param moref: managed object reference
:param property_name: name of the property to be retrieved
:param skip_op_id: whether to skip putting opID in the request
:returns: property of the given managed object
:raises: VimException, VimFaultException, VimAttributeException,
VimSessionOverLoadException, VimConnectionException
"""
props = get_object_properties(vim, moref, [property_name])
props = get_object_properties(vim, moref, [property_name],
skip_op_id=skip_op_id)
prop_val = None
if props:
prop = None