opentelemetry-instrumentation-grpc client instrumentation fails if channel has interceptors

[iredelmeier]

Describe your environment

Verified on python 3.8.6 with opentelemetry 0.17b0

Steps to reproduce

tl;dr: GrpcInstrumentorClient().instrument() + a channel intercepted with grpc.intercept_channel

Based on the gRPC helloworld example, sub out greeter_client.py for:

# Copyright 2015 gRPC authors.
#
# Licensed under the Apache License, Version 2.0 (the "License");
# you may not use this file except in compliance with the License.
# You may obtain a copy of the License at
#
#     http://www.apache.org/licenses/LICENSE-2.0
#
# Unless required by applicable law or agreed to in writing, software
# distributed under the License is distributed on an "AS IS" BASIS,
# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
# See the License for the specific language governing permissions and
# limitations under the License.
"""The Python implementation of the GRPC helloworld.Greeter client."""

from __future__ import print_function
import logging

import grpc

from opentelemetry import trace
from opentelemetry.instrumentation.grpc import GrpcInstrumentorClient
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import (
    ConsoleSpanExporter,
    SimpleExportSpanProcessor,
)

import helloworld_pb2
import helloworld_pb2_grpc

trace.set_tracer_provider(TracerProvider())
trace.get_tracer_provider().add_span_processor(
    SimpleExportSpanProcessor(ConsoleSpanExporter())
)

GrpcInstrumentorClient().instrument()


class Interceptor(
    grpc.UnaryUnaryClientInterceptor,
    grpc.UnaryStreamClientInterceptor,
    grpc.StreamUnaryClientInterceptor,
    grpc.StreamStreamClientInterceptor,
):
    def intercept_unary_unary(self, continuation, client_call_details, request):
        return self._intercept_call(continuation, client_call_details, request)

    def intercept_unary_stream(self, continuation, client_call_details, request):
        return self._intercept_call(continuation, client_call_details, request)

    def intercept_stream_unary(self, continuation, client_call_details, request_iterator):
        return self._intercept_call(continuation, client_call_details, request_iterator)

    def intercept_stream_stream(self, continuation, client_call_details, request_iterator):
        return self._intercept_call(continuation, client_call_details, request_iterator)

    def _intercept_call(self, continuation, client_call_details, request_or_iterator):
        return continuation(client_call_details, request_or_iterator)


def run():
    # NOTE(gRPC Python Team): .close() is possible on a channel and should be
    # used in circumstances in which the with statement does not fit the needs
    # of the code.
    interceptors = [Interceptor()]
    channel = grpc.insecure_channel('localhost:50051')
    channel = grpc.intercept_channel(channel, *interceptors)
    stub = helloworld_pb2_grpc.GreeterStub(channel)
    response = stub.SayHello(helloworld_pb2.HelloRequest(name='you'))
    print("Greeter client received: " + response.message)


if __name__ == '__main__':
    logging.basicConfig()
    run()

What is the expected behavior?

The client should continue to behave as a standard, working gRPC client, now with instrumentation

What is the actual behavior?

Requests made through the client now error, e.g.:

❯ python greeter_client.py
Traceback (most recent call last):
  File "greeter_client.py", line 76, in <module>
    run()
  File "greeter_client.py", line 70, in run
    response = stub.SayHello(helloworld_pb2.HelloRequest(name='you'))
  File "/home/isobel/workspace/tmp/otlp/grpc/lib/python3.8/site-packages/grpc/_interceptor.py", line 216, in __call__
    response, ignored_call = self._with_call(request,
  File "/home/isobel/workspace/tmp/otlp/grpc/lib/python3.8/site-packages/grpc/_interceptor.py", line 257, in _with_call
    return call.result(), call
  File "/home/isobel/workspace/tmp/otlp/grpc/lib/python3.8/site-packages/grpc/_interceptor.py", line 126, in result
    raise self._exception
  File "/home/isobel/workspace/tmp/otlp/grpc/lib/python3.8/site-packages/grpc/_interceptor.py", line 241, in continuation
    response, call = self._thunk(new_method).with_call(
TypeError: with_call() got an unexpected keyword argument 'wait_for_ready'

Note: I've so far only verified this causes problems with UnaryUnary requests. I assume that some or all of the other types fail similarly.

Additional context

Happy to fix this myself :)

[alertedsnake]

Ugh, I knew this one was going to come up based on the hidden magic of how the "wrapper" thing was initially designed, it's why I redesigned the server part to be able to handle an existing interceptor chain.

It should be a pretty easy fix, just to mimic how it's done in the server. If you want to work on it @iredelmeier, say so - otherwise I could probably get to it myself :)

[github-actions]

This issue was marked stale due to lack of activity. It will be closed in 30 days.

[mihirg]

I have raised a PR to fix this. #442

[github-actions]

This issue was marked stale due to lack of activity. It will be closed in 30 days.

[lzchen]

@mihirg
Is this issue resolved?

[codeboten]

I ran the code with the following packages installed

opentelemetry-api==1.3.0
opentelemetry-instrumentation==0.22b0
opentelemetry-instrumentation-grpc==0.22b0
opentelemetry-sdk==1.3.0
opentelemetry-semantic-conventions==0.22b0

and got the following output:

python test.py
{
    "name": "/helloworld.Greeter/SayHello",
    "context": {
        "trace_id": "0x0f84fcc92383f443e2fb4e31ed7576da",
        "span_id": "0x870f5828f8bd1c69",
        "trace_state": "[]"
    },
    "kind": "SpanKind.CLIENT",
    "parent_id": null,
    "start_time": "2021-07-12T15:11:16.071102Z",
    "end_time": "2021-07-12T15:11:16.072462Z",
    "status": {
        "status_code": "UNSET"
    },
    "attributes": {
        "rpc.system": "grpc",
        "rpc.grpc.status_code": 0,
        "rpc.method": "SayHello",
        "rpc.service": "helloworld.Greeter"
    },
    "events": [],
    "links": [],
    "resource": {
        "telemetry.sdk.language": "python",
        "telemetry.sdk.name": "opentelemetry",
        "telemetry.sdk.version": "1.3.0",
        "service.name": "unknown_service"
    }
}

I believe this issue has been fixed. Please re-open if that's not the case @iredelmeier