Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Unable to close grpc_channel. Connection was interrupted on the server side #465

Open
romqn1999 opened this issue Jan 30, 2024 · 12 comments
Open

Unable to close grpc_channel. Connection was interrupted on the server side #465

romqn1999 opened this issue Jan 30, 2024 · 12 comments
Labels
bug Something isn't working

Comments

@romqn1999
Copy link

I set up a Qdrant Vector DB in a Docker container and created a Python script to query the Vector DB using QdrantClient. However, after executing all queries, when the QdrantClient attempts to close the connection, it throws an error stating, "Unable to close grpc_channel. Connection was interrupted on the server side."

Current Behavior

The error message from QdrantClient:

[2024-01-30 12:27:28,956-WARNING: close:163] Unable to close grpc_channel. Connection was interrupted on the server side
Exception ignored in: <function QdrantClient.__del__ at 0x7fea068b9ee0>
Traceback (most recent call last):
  File "/lib/python3.9/site-packages/qdrant_client/qdrant_client.py", line 132, in __del__
  File "/lib/python3.9/site-packages/qdrant_client/qdrant_client.py", line 139, in close
  File "/lib/python3.9/site-packages/qdrant_client/qdrant_remote.py", line 163, in close
  File "/lib/python3.9/logging/__init__.py", line 2082, in warning
  File "/lib/python3.9/logging/__init__.py", line 1458, in warning
  File "/lib/python3.9/logging/__init__.py", line 1589, in _log
  File "/lib/python3.9/logging/__init__.py", line 1599, in handle
  File "/lib/python3.9/site-packages/sentry_sdk/integrations/logging.py", line 102, in sentry_patched_callhandlers
TypeError: argument of type 'NoneType' is not iterable

Steps to Reproduce

  1. Config the vector DB using docker-compose
version: '3.9'

services:
    vector-db:
        image: qdrant/qdrant
        volumes:
            - ./data/qdrant_storage:/qdrant/storage:z
        ports:
            - 6333:6333
            - 6334:6334
        networks:
            - my-net

networks:
  my-net:
  1. Initialize QdrantClient in a custom Python class's __init__ method to execute queries in other methods:
class MyClass(ABC):
    def __init__(self):
        self.vector_db_client = QdrantClient("vector-db", prefer_grpc=True)

    def my_func(self):
        # Make queries to the Vector DB using `self.vector_db_client`
  1. Run the script and encounter the above error upon exiting.

Expected Behavior

The script should exit successfully without any errors.

Context (Environment)

  • Qdrant Vector DB: v1.7.3
  • qdrant-client: v1.7.1
@romqn1999 romqn1999 added the bug Something isn't working label Jan 30, 2024
@timvisee
Copy link
Member

Do you stop the container before or after closing the client?

@romqn1999
Copy link
Author

No, the container is still running.

@timvisee timvisee transferred this issue from qdrant/qdrant Jan 30, 2024
@joein
Copy link
Member

joein commented Jan 30, 2024

Are there any logs in the container?

@romqn1999
Copy link
Author

Logs from the container:

$ docker logs -f vector-db-1
           _                 _    
  __ _  __| |_ __ __ _ _ __ | |_  
 / _` |/ _` | '__/ _` | '_ \| __| 
| (_| | (_| | | | (_| | | | | |_  
 \__, |\__,_|_|  \__,_|_| |_|\__| 
    |_|                           

Access web UI at http://0.0.0.0:6333/dashboard

2024-01-30T05:15:39.925684Z  INFO storage::content_manager::consensus::persistent: Loading raft state from ./storage/raft_state.json       
2024-01-30T05:16:04.807505Z  INFO storage::content_manager::toc: Loading collection: user_emb    
2024-01-30T05:16:14.101076Z  INFO storage::content_manager::toc: Loading collection: item_emb    
2024-01-30T05:16:14.229290Z  INFO qdrant: Distributed mode disabled    
2024-01-30T05:16:14.229318Z  INFO qdrant: Telemetry reporting enabled, id: cb82a921-d38e-41ee-90c0-9ceb7c2ee0d1    
2024-01-30T05:16:14.238894Z  INFO qdrant::tonic: Qdrant gRPC listening on 6334    
2024-01-30T05:16:14.238924Z  INFO qdrant::tonic: TLS disabled for gRPC API    
2024-01-30T05:16:14.239222Z  INFO qdrant::actix: TLS disabled for REST API    
2024-01-30T05:16:14.239476Z  INFO qdrant::actix: Qdrant HTTP listening on 6333    
2024-01-30T05:16:14.239497Z  INFO actix_server::builder: Starting 63 workers
2024-01-30T05:16:14.239516Z  INFO actix_server::server: Actix runtime found; starting in Actix runtime
2024-01-30T06:16:06.842397Z  INFO actix_web::middleware::logger: x.x.x.x "GET /dashboard/assets/index-014e4952.css HTTP/1.1" 200 32159 "http://y.y.y.y:6333/dashboard" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" 0.002809    
2024-01-30T06:16:06.977221Z  INFO actix_web::middleware::logger: x.x.x.x "GET /dashboard/assets/index-9558a693.js HTTP/1.1" 200 1697433 "http://y.y.y.y:6333/dashboard" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" 0.138256    
2024-01-30T06:16:07.464954Z  INFO actix_web::middleware::logger: x.x.x.x "GET /telemetry HTTP/1.1" 200 358 "http://y.y.y.y:6333/dashboard" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" 0.000534    
2024-01-30T06:16:07.530184Z  INFO actix_web::middleware::logger: x.x.x.x "GET /dashboard/openapi.json HTTP/1.1" 200 45554 "http://y.y.y.y:6333/dashboard" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" 0.002767    
2024-01-30T06:16:07.688511Z  INFO actix_web::middleware::logger: x.x.x.x "GET /collections HTTP/1.1" 200 166 "http://y.y.y.y:6333/dashboard" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" 0.000172    
2024-01-30T06:16:07.749565Z  INFO actix_web::middleware::logger: x.x.x.x "GET /dashboard/assets/editor.worker-01324a4b.js HTTP/1.1" 200 80295 "http://y.y.y.y:6333/dashboard" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" 0.003138    
2024-01-30T06:16:07.918943Z  INFO actix_web::middleware::logger: x.x.x.x "GET /dashboard/assets/codicon-8b349ebc.ttf HTTP/1.1" 200 46405 "http://y.y.y.y:6333/dashboard/assets/index-014e4952.css" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" 0.003582    
2024-01-30T06:16:15.059907Z  INFO actix_web::middleware::logger: x.x.x.x "GET /dashboard/assets/jsonMode-a15a0cf4.js HTTP/1.1" 200 13817 "http://y.y.y.y:6333/dashboard/assets/index-9558a693.js" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" 0.002896    
2024-01-30T06:16:15.172856Z  INFO actix_web::middleware::logger: x.x.x.x "GET /collections HTTP/1.1" 200 167 "http://y.y.y.y:6333/dashboard" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" 0.000347    
2024-01-30T06:16:15.193394Z  INFO actix_web::middleware::logger: x.x.x.x "GET /dashboard/assets/json.worker-dcfd985a.js HTTP/1.1" 200 126407 "http://y.y.y.y:6333/dashboard" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" 0.012863    
2024-01-30T06:16:17.171795Z  INFO actix_web::middleware::logger: x.x.x.x "GET /collections HTTP/1.1" 200 166 "http://y.y.y.y:6333/dashboard" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" 0.000362    
2024-01-30T06:16:18.394516Z  INFO actix_web::middleware::logger: x.x.x.x "GET /dashboard/assets/prism-json-7ae4e91d.js HTTP/1.1" 200 275 "http://y.y.y.y:6333/dashboard/assets/index-9558a693.js" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" 0.000985    
2024-01-30T11:04:56.380292Z  INFO actix_web::middleware::logger: x.x.x.x "GET /telemetry HTTP/1.1" 200 495 "http://y.y.y.y:6333/dashboard" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" 0.002199

It appears that the logs don't show any messages related to my queries, even though my queries were successfully executed.

@timvisee
Copy link
Member

It appears that the logs don't show any messages related to my queries, even though my queries were successfully executed.

Your queries might go over gRPC. We only log REST requests, not gRPC requests.

@romqn1999
Copy link
Author

romqn1999 commented Jan 31, 2024 •
edited
Loading

Ah, I see. Even after changing the QdrantClient without prefer_grpc, I'm still encountering the error.

Logs from the container:

2024-01-31T09:11:16.432574Z  INFO actix_web::middleware::logger: x.x.x.x "POST /collections/item_emb/points/scroll HTTP/1.1" 200 675463 "-" "python-httpx/0.25.0" 0.068555    
2024-01-31T09:11:17.521822Z  INFO actix_web::middleware::logger: x.x.x.x "POST /collections/item_emb/points/search/batch HTTP/1.1" 200 220599 "-" "python-httpx/0.25.0" 0.121472

Logs from the client:

$ python my_script.py
[2024-01-31 16:15:58,376-DEBUG: load_ssl_context:79] load_ssl_context verify=True cert=None trust_env=True http2=False
[2024-01-31 16:15:58,377-DEBUG: load_ssl_context_verify:146] load_verify_locations cafile='/home/daclth/.local/lib/python3.9/site-packages/certifi/cacert.pem'
[2024-01-31 16:15:58,453-DEBUG: load_ssl_context:79] load_ssl_context verify=True cert=None trust_env=True http2=False
[2024-01-31 16:15:58,454-DEBUG: load_ssl_context_verify:146] load_verify_locations cafile='/home/daclth/.local/lib/python3.9/site-packages/certifi/cacert.pem'
[2024-01-31 16:15:59,437-DEBUG: trace:45] connect_tcp.started host='x.x.x.x' port=6333 local_address=None timeout=5.0 socket_options=None
[2024-01-31 16:15:59,438-DEBUG: trace:45] connect_tcp.complete return_value=<httpcore._backends.sync.SyncStream object at 0x7f58ed3ca430>
[2024-01-31 16:15:59,438-DEBUG: trace:45] send_request_headers.started request=<Request [b'POST']>
[2024-01-31 16:15:59,438-DEBUG: trace:45] send_request_headers.complete
[2024-01-31 16:15:59,438-DEBUG: trace:45] send_request_body.started request=<Request [b'POST']>
[2024-01-31 16:15:59,439-DEBUG: trace:45] send_request_body.complete
[2024-01-31 16:15:59,439-DEBUG: trace:45] receive_response_headers.started request=<Request [b'POST']>
[2024-01-31 16:15:59,460-DEBUG: trace:45] receive_response_headers.complete return_value=(b'HTTP/1.1', 200, b'OK', [(b'transfer-encoding', b'chunked'), (b'content-type', b'application/json'), (b'content-encoding', b'gzip'), (b'vary', b'accept-encoding, Origin, Access-Control-Request-Method, Access-Control-Request-Headers'), (b'date', b'Wed, 31 Jan 2024 09:15:59 GMT')])
[2024-01-31 16:15:59,462-INFO: _send_single_request:1013] HTTP Request: POST http://x.x.x.x:6333/collections/item_emb/points/scroll "HTTP/1.1 200 OK"
[2024-01-31 16:15:59,463-DEBUG: trace:45] receive_response_body.started request=<Request [b'POST']>
[2024-01-31 16:15:59,511-DEBUG: trace:45] receive_response_body.complete
[2024-01-31 16:15:59,511-DEBUG: trace:45] response_closed.started
[2024-01-31 16:15:59,511-DEBUG: trace:45] response_closed.complete
[2024-01-31 16:16:00,443-DEBUG: trace:45] send_request_headers.started request=<Request [b'POST']>
[2024-01-31 16:16:00,443-DEBUG: trace:45] send_request_headers.complete
[2024-01-31 16:16:00,443-DEBUG: trace:45] send_request_body.started request=<Request [b'POST']>
[2024-01-31 16:16:00,449-DEBUG: trace:45] send_request_body.complete
[2024-01-31 16:16:00,449-DEBUG: trace:45] receive_response_headers.started request=<Request [b'POST']>
[2024-01-31 16:16:00,565-DEBUG: trace:45] receive_response_headers.complete return_value=(b'HTTP/1.1', 200, b'OK', [(b'transfer-encoding', b'chunked'), (b'content-type', b'application/json'), (b'content-encoding', b'gzip'), (b'vary', b'accept-encoding, Origin, Access-Control-Request-Method, Access-Control-Request-Headers'), (b'date', b'Wed, 31 Jan 2024 09:16:00 GMT')])
[2024-01-31 16:16:00,565-INFO: _send_single_request:1013] HTTP Request: POST http://x.x.x.x:6333/collections/item_emb/points/search/batch "HTTP/1.1 200 OK"
[2024-01-31 16:16:00,566-DEBUG: trace:45] receive_response_body.started request=<Request [b'POST']>
[2024-01-31 16:16:00,580-DEBUG: trace:45] receive_response_body.complete
[2024-01-31 16:16:00,581-DEBUG: trace:45] response_closed.started
[2024-01-31 16:16:00,581-DEBUG: trace:45] response_closed.complete
[2024-01-31 16:16:00,992-DEBUG: trace:45] close.started
[2024-01-31 16:16:00,992-WARNING: close:181] Unable to close http connection. Connection was interrupted on the server side
Exception ignored in: <function QdrantClient.__del__ at 0x7f5860a153a0>
Traceback (most recent call last):
  File "/lib/python3.9/site-packages/qdrant_client/qdrant_client.py", line 132, in __del__
  File "/lib/python3.9/site-packages/qdrant_client/qdrant_client.py", line 139, in close
  File "/lib/python3.9/site-packages/qdrant_client/qdrant_remote.py", line 181, in close
  File "/lib/python3.9/logging/__init__.py", line 2082, in warning
  File "/lib/python3.9/logging/__init__.py", line 1458, in warning
  File "/lib/python3.9/logging/__init__.py", line 1589, in _log
  File "/lib/python3.9/logging/__init__.py", line 1599, in handle
  File "/lib/python3.9/site-packages/sentry_sdk/integrations/logging.py", line 102, in sentry_patched_callhandlers
TypeError: argument of type 'NoneType' is not iterable

@joein
Copy link
Member

joein commented Jan 31, 2024

I could not reproduce the error with the code sample you've provided :(
Are you sure it is reproducible with the code sample?

Could you maybe tell us your operation system, python version, etc?

@romqn1999
Copy link
Author

Ah, I've discovered that the issue occurs when I include from feast import FeatureStore. The error disappears when I comment out this line.

@joein
Copy link
Member

joein commented Feb 1, 2024

It would be highly appreciated if you could provide a code sample to reproduce the issue, otherwise we'll have to put it on hold for a while before we can dig into it.

@romqn1999
Copy link
Author

Here's the code snippet to reproduce the issue:

from qdrant_client import QdrantClient
from feast import FeatureStore


class MyClass():
    def __init__(self, vector_db_host, vector_db_port):
        self.vector_db_client = QdrantClient(vector_db_host, grpc_port=vector_db_port, prefer_grpc=True)

    def my_func(self):
        return self.vector_db_client.get_collections()


if __name__ == "__main__":
    obj = MyClass("x.x.x.x", 6334)
    res = obj.my_func()
    print(res)

@joein
Copy link
Member

joein commented Feb 2, 2024

It is indeed reproducible with feast, I will take a closer look, thanks

@joein
Copy link
Member

joein commented Feb 3, 2024 •
edited
Loading

At the moment It seems like feast (or its dependencies) might be messing up with python's garbage collector

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@timvisee @joein @romqn1999