|
| 1 | +"""Implementation of the invocation-side open-tracing interceptor.""" |
| 2 | + |
| 3 | +import sys |
| 4 | +import logging |
| 5 | +import time |
| 6 | + |
| 7 | +from six import iteritems |
| 8 | + |
| 9 | +import grpc |
| 10 | +from grpc_opentracing import grpcext |
| 11 | +from grpc_opentracing._utilities import get_method_type, get_deadline_millis,\ |
| 12 | + log_or_wrap_request_or_iterator, RpcInfo |
| 13 | +import opentracing |
| 14 | +from opentracing.ext import tags as ot_tags |
| 15 | + |
| 16 | + |
| 17 | +class _GuardedSpan(object): |
| 18 | + |
| 19 | + def __init__(self, span): |
| 20 | + self.span = span |
| 21 | + self._engaged = True |
| 22 | + |
| 23 | + def __enter__(self): |
| 24 | + self.span.__enter__() |
| 25 | + return self |
| 26 | + |
| 27 | + def __exit__(self, *args, **kwargs): |
| 28 | + if self._engaged: |
| 29 | + return self.span.__exit__(*args, **kwargs) |
| 30 | + else: |
| 31 | + return False |
| 32 | + |
| 33 | + def release(self): |
| 34 | + self._engaged = False |
| 35 | + return self.span |
| 36 | + |
| 37 | + |
| 38 | +def _inject_span_context(tracer, span, metadata): |
| 39 | + headers = {} |
| 40 | + try: |
| 41 | + tracer.inject(span.context, opentracing.Format.HTTP_HEADERS, headers) |
| 42 | + except (opentracing.UnsupportedFormatException, |
| 43 | + opentracing.InvalidCarrierException, |
| 44 | + opentracing.SpanContextCorruptedException) as e: |
| 45 | + logging.exception('tracer.inject() failed') |
| 46 | + span.log_kv({'event': 'error', 'error.object': e}) |
| 47 | + return metadata |
| 48 | + metadata = () if metadata is None else tuple(metadata) |
| 49 | + return metadata + tuple((k.lower(), v) for (k, v) in iteritems(headers)) |
| 50 | + |
| 51 | + |
| 52 | +def _make_future_done_callback(span, rpc_info, log_payloads, span_decorator): |
| 53 | + |
| 54 | + def callback(response_future): |
| 55 | + with span: |
| 56 | + code = response_future.code() |
| 57 | + if code != grpc.StatusCode.OK: |
| 58 | + span.set_tag('error', True) |
| 59 | + error_log = {'event': 'error', 'error.kind': str(code)} |
| 60 | + details = response_future.details() |
| 61 | + if details is not None: |
| 62 | + error_log['message'] = details |
| 63 | + span.log_kv(error_log) |
| 64 | + rpc_info.error = code |
| 65 | + if span_decorator is not None: |
| 66 | + span_decorator(span, rpc_info) |
| 67 | + return |
| 68 | + response = response_future.result() |
| 69 | + rpc_info.response = response |
| 70 | + if log_payloads: |
| 71 | + span.log_kv({'response': response}) |
| 72 | + if span_decorator is not None: |
| 73 | + span_decorator(span, rpc_info) |
| 74 | + |
| 75 | + return callback |
| 76 | + |
| 77 | + |
| 78 | +class OpenTracingClientInterceptor(grpcext.UnaryClientInterceptor, |
| 79 | + grpcext.StreamClientInterceptor): |
| 80 | + |
| 81 | + def __init__(self, tracer, active_span_source, log_payloads, |
| 82 | + span_decorator): |
| 83 | + self._tracer = tracer |
| 84 | + self._active_span_source = active_span_source |
| 85 | + self._log_payloads = log_payloads |
| 86 | + self._span_decorator = span_decorator |
| 87 | + |
| 88 | + def _start_span(self, method): |
| 89 | + active_span_context = None |
| 90 | + if self._active_span_source is not None: |
| 91 | + active_span = self._active_span_source.get_active_span() |
| 92 | + if active_span is not None: |
| 93 | + active_span_context = active_span.context |
| 94 | + tags = { |
| 95 | + ot_tags.COMPONENT: 'grpc', |
| 96 | + ot_tags.SPAN_KIND: ot_tags.SPAN_KIND_RPC_CLIENT |
| 97 | + } |
| 98 | + return self._tracer.start_span( |
| 99 | + operation_name=method, child_of=active_span_context, tags=tags) |
| 100 | + |
| 101 | + def _trace_result(self, guarded_span, rpc_info, result): |
| 102 | + # If the RPC is called asynchronously, release the guard and add a callback |
| 103 | + # so that the span can be finished once the future is done. |
| 104 | + if isinstance(result, grpc.Future): |
| 105 | + result.add_done_callback( |
| 106 | + _make_future_done_callback(guarded_span.release( |
| 107 | + ), rpc_info, self._log_payloads, self._span_decorator)) |
| 108 | + return result |
| 109 | + response = result |
| 110 | + # Handle the case when the RPC is initiated via the with_call |
| 111 | + # method and the result is a tuple with the first element as the |
| 112 | + # response. |
| 113 | + # http://www.grpc.io/grpc/python/grpc.html#grpc.UnaryUnaryMultiCallable.with_call |
| 114 | + if isinstance(result, tuple): |
| 115 | + response = result[0] |
| 116 | + rpc_info.response = response |
| 117 | + if self._log_payloads: |
| 118 | + guarded_span.span.log_kv({'response': response}) |
| 119 | + if self._span_decorator is not None: |
| 120 | + self._span_decorator(guarded_span.span, rpc_info) |
| 121 | + return result |
| 122 | + |
| 123 | + def _start_guarded_span(self, *args, **kwargs): |
| 124 | + return _GuardedSpan(self._start_span(*args, **kwargs)) |
| 125 | + |
| 126 | + def intercept_unary(self, request, metadata, client_info, invoker): |
| 127 | + with self._start_guarded_span(client_info.full_method) as guarded_span: |
| 128 | + metadata = _inject_span_context(self._tracer, guarded_span.span, |
| 129 | + metadata) |
| 130 | + rpc_info = RpcInfo( |
| 131 | + full_method=client_info.full_method, |
| 132 | + metadata=metadata, |
| 133 | + timeout=client_info.timeout, |
| 134 | + request=request) |
| 135 | + if self._log_payloads: |
| 136 | + guarded_span.span.log_kv({'request': request}) |
| 137 | + try: |
| 138 | + result = invoker(request, metadata) |
| 139 | + except: |
| 140 | + e = sys.exc_info()[0] |
| 141 | + guarded_span.span.set_tag('error', True) |
| 142 | + guarded_span.span.log_kv({'event': 'error', 'error.object': e}) |
| 143 | + rpc_info.error = e |
| 144 | + if self._span_decorator is not None: |
| 145 | + self._span_decorator(guarded_span.span, rpc_info) |
| 146 | + raise |
| 147 | + return self._trace_result(guarded_span, rpc_info, result) |
| 148 | + |
| 149 | + # For RPCs that stream responses, the result can be a generator. To record |
| 150 | + # the span across the generated responses and detect any errors, we wrap the |
| 151 | + # result in a new generator that yields the response values. |
| 152 | + def _intercept_server_stream(self, request_or_iterator, metadata, |
| 153 | + client_info, invoker): |
| 154 | + with self._start_span(client_info.full_method) as span: |
| 155 | + metadata = _inject_span_context(self._tracer, span, metadata) |
| 156 | + rpc_info = RpcInfo( |
| 157 | + full_method=client_info.full_method, |
| 158 | + metadata=metadata, |
| 159 | + timeout=client_info.timeout) |
| 160 | + if client_info.is_client_stream: |
| 161 | + rpc_info.request = request_or_iterator |
| 162 | + if self._log_payloads: |
| 163 | + request_or_iterator = log_or_wrap_request_or_iterator( |
| 164 | + span, client_info.is_client_stream, request_or_iterator) |
| 165 | + try: |
| 166 | + result = invoker(request_or_iterator, metadata) |
| 167 | + for response in result: |
| 168 | + if self._log_payloads: |
| 169 | + span.log_kv({'response': response}) |
| 170 | + yield response |
| 171 | + except: |
| 172 | + e = sys.exc_info()[0] |
| 173 | + span.set_tag('error', True) |
| 174 | + span.log_kv({'event': 'error', 'error.object': e}) |
| 175 | + rpc_info.error = e |
| 176 | + if self._span_decorator is not None: |
| 177 | + self._span_decorator(span, rpc_info) |
| 178 | + raise |
| 179 | + if self._span_decorator is not None: |
| 180 | + self._span_decorator(span, rpc_info) |
| 181 | + |
| 182 | + def intercept_stream(self, request_or_iterator, metadata, client_info, |
| 183 | + invoker): |
| 184 | + if client_info.is_server_stream: |
| 185 | + return self._intercept_server_stream(request_or_iterator, metadata, |
| 186 | + client_info, invoker) |
| 187 | + with self._start_guarded_span(client_info.full_method) as guarded_span: |
| 188 | + metadata = _inject_span_context(self._tracer, guarded_span.span, |
| 189 | + metadata) |
| 190 | + rpc_info = RpcInfo( |
| 191 | + full_method=client_info.full_method, |
| 192 | + metadata=metadata, |
| 193 | + timeout=client_info.timeout, |
| 194 | + request=request_or_iterator) |
| 195 | + if self._log_payloads: |
| 196 | + request_or_iterator = log_or_wrap_request_or_iterator( |
| 197 | + guarded_span.span, client_info.is_client_stream, |
| 198 | + request_or_iterator) |
| 199 | + try: |
| 200 | + result = invoker(request_or_iterator, metadata) |
| 201 | + except: |
| 202 | + e = sys.exc_info()[0] |
| 203 | + guarded_span.span.set_tag('error', True) |
| 204 | + guarded_span.span.log_kv({'event': 'error', 'error.object': e}) |
| 205 | + rpc_info.error = e |
| 206 | + if self._span_decorator is not None: |
| 207 | + self._span_decorator(guarded_span.span, rpc_info) |
| 208 | + raise |
| 209 | + return self._trace_result(guarded_span, rpc_info, result) |
0 commit comments