Invalid method encountered or duplicate "Content-Length" header?

I am not sure what is underlying issue here.

I have same code working when I am running with Local(same MBP) kubernetes deployment, but with kubernetes deployed on EKS I am seeing this pretty ambiguous error(at least I can’t figure this out with errors).

Here is the code -

from fastapi import FastAPI, HTTPException
from fastapi.responses import JSONResponse
from fastapi import status
from pydantic import BaseModel
import ray
from ray import serve
import logging



logger = logging.getLogger(__name__)
logger.setLevel(logging.INFO)

app = FastAPI()
ray.init(address="auto", namespace="ray", log_to_driver=True, logging_level=logging.INFO)
serve.start(detached=True)



class InRequest(BaseModel):
    text: str

@serve.deployment(route_prefix='/api', num_replicas=1)
@serve.ingress(app)
class InspectFlair:
    @app.post('/entities')
    def inspect(self, request: InRequest):
        if len(request.text) == 0:
            raise HTTPException(status_code=400, detail="'text' not found!")
        try:

            data = request.text
            logger.error(f"ERR - Request: {request}, data: {data}")
            flair_handle = serve.get_deployment("FlairTokenizer").get_handle()
            future = flair_handle.remote(data)
            response = ray.get(future)
            logger.error(f"ERR - Response: {response}") 
            return JSONResponse(status_code=status.HTTP_200_OK, content=response)
        except ValueError:
            return {'error': ValueError}, 400

InspectFlair.deploy()



  1. Curl call response - Duplicate Content-Length is clearly visible but no errors.
❯ curl -ki -H "Content-Type:application/json" -d '{"text":"I live in california"}' http://127.0.0.1:8000/api/entities
HTTP/1.1 200 OK
date: Tue, 25 Jan 2022 23:01:06 GMT
server: uvicorn
content-length: 30
content-length: 30
content-type: application/json

{"predictions":["california"]}%



  1. POSTMAN response for same request - Received error.
  • Stacktrace from head-node suggests that this is some invalid http method.
	INFO:     Started server process [422]
WARNING:  Invalid HTTP request received.
Traceback (most recent call last):
  File "/home/ray/anaconda3/lib/python3.7/site-packages/uvicorn/protocols/http/httptools_impl.py", line 132, in data_received
    self.parser.feed_data(data)
  File "httptools/parser/parser.pyx", line 212, in httptools.parser.parser.HttpParser.feed_data
httptools.parser.errors.HttpParserInvalidMethodError: Invalid method encountered
WARNING:  Invalid HTTP request received.
Traceback (most recent call last):
  File "/home/ray/anaconda3/lib/python3.7/site-packages/uvicorn/protocols/http/httptools_impl.py", line 132, in data_received
    self.parser.feed_data(data)
  File "httptools/parser/parser.pyx", line 212, in httptools.parser.parser.HttpParser.feed_data
httptools.parser.errors.HttpParserInvalidMethodError: Invalid method encountered
WARNING:  Invalid HTTP request received.
Traceback (most recent call last):
  File "/home/ray/anaconda3/lib/python3.7/site-packages/uvicorn/protocols/http/httptools_impl.py", line 132, in data_received
    self.parser.feed_data(data)
  File "httptools/parser/parser.pyx", line 212, in httptools.parser.parser.HttpParser.feed_data
httptools.parser.errors.HttpParserInvalidMethodError: Invalid method encountered
WARNING:  Invalid HTTP request received.
Traceback (most recent call last):
  File "/home/ray/anaconda3/lib/python3.7/site-packages/uvicorn/protocols/http/httptools_impl.py", line 132, in data_received
    self.parser.feed_data(data)
  File "httptools/parser/parser.pyx", line 212, in httptools.parser.parser.HttpParser.feed_data
httptools.parser.errors.HttpParserInvalidMethodError: Invalid method encountered



I checked with uvicorn as well as FastAPI and this seems to be generating from uvicorn but not sure how to avoid this or is there any other issue.

I am following recommended way to integrate with FastAPI via native integration. Do we have any option to disable header originating from ray.serve? or is there any other solution to this?

The issue was h11's version issue. See [Bug] Ray Serve End-to-End tutorial not working with Ray 1.9.0 on Windows Β· Issue #20513 Β· ray-project/ray Β· GitHub and try pip install -U h11

Hi @simon-mo ,

I upgraded(head and worker nodes) as you suggested but its still same. I can still see duplicate content-length header.

(base) ray@example-cluster-ray-head-type-m9ccv:/app$ pip list | grep h11
h11                                    0.12.0
(base) ray@example-cluster-ray-head-type-m9ccv:/app$ pip install -U h11
Requirement already satisfied: h11 in /home/ray/anaconda3/lib/python3.7/site-packages (0.12.0)
Collecting h11
  Downloading h11-0.13.0-py3-none-any.whl (58 kB)
     |β–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆ| 58 kB 2.0 MB/s
Requirement already satisfied: typing-extensions in /home/ray/anaconda3/lib/python3.7/site-packages (from h11) (3.10.0.2)
Installing collected packages: h11
  Attempting uninstall: h11
    Found existing installation: h11 0.12.0
    Uninstalling h11-0.12.0:
      Successfully uninstalled h11-0.12.0
Successfully installed h11-0.13.0

curl request -

❯ curl -ki -H "Content-Type:application/json" -d '{"text":"I live in california"}' http://127.0.0.1:8000/api/entities
HTTP/1.1 200 OK
date: Wed, 26 Jan 2022 00:05:37 GMT
server: uvicorn
content-length: 30
content-length: 30
content-type: application/json

{"predictions":["california"]}%

What’s the uvicorn version? Thanks

Its uvicorn==0.16.0

I tried to reproduce it but can’t see it. Here’s the log, the only change is that I dropped lines calling FlairTokenizer

(ray-repro) ➜  /tmp pip install -qq 'ray[serve]' uvicorn==0.16 h11==0.13
(ray-repro) ➜  /tmp ray start --head
...
(ray-repro) ➜  /tmp python a.py
2022-01-25 16:22:55,677	INFO worker.py:843 -- Connecting to existing Ray cluster at address: 127.0.0.1:6379
(ServeController pid=53785) 2022-01-25 16:22:56,538	INFO checkpoint_path.py:16 -- Using RayInternalKVStore for controller checkpoint and recovery.
(ServeController pid=53785) 2022-01-25 16:22:56,540	INFO http_state.py:101 -- Starting HTTP proxy with name 'SERVE_CONTROLLER_ACTOR:SERVE_PROXY_ACTOR-node:127.0.0.1-0' on node 'node:127.0.0.1-0' listening on '127.0.0.1:8000'
2022-01-25 16:22:57,270	INFO api.py:463 -- Started detached Serve instance in namespace 'ray'.
2022-01-25 16:22:57,284	INFO api.py:242 -- Updating deployment 'InspectFlair'. component=serve deployment=InspectFlair
(HTTPProxyActor pid=53789) INFO:     Started server process [53789]
(ServeController pid=53785) 2022-01-25 16:22:57,388	INFO deployment_state.py:912 -- Adding 1 replicas to deployment 'InspectFlair'. component=serve deployment=InspectFlair
2022-01-25 16:22:58,153	INFO api.py:250 -- Deployment 'InspectFlair' is ready at `http://127.0.0.1:8000/api`. component=serve deployment=InspectFlair
(ray-repro) ➜  /tmp cat a.py
...
            data = request.text
            logger.error(f"ERR - Request: {request}, data: {data}")
            # flair_handle = serve.get_deployment("FlairTokenizer").get_handle()
            # future = flair_handle.remote(data)
            # response = ray.get(future)
            # logger.error(f"ERR - Response: {response}")
            return JSONResponse(status_code=status.HTTP_200_OK, content=request.text)
...
(ray-repro) ➜  /tmp curl -ki -H "Content-Type:application/json" -d '{"text":"I live in california"}' http://127.0.0.1:8000/api/entities
HTTP/1.1 200 OK
date: Wed, 26 Jan 2022 00:23:05 GMT
server: uvicorn
content-length: 22
content-type: application/json

"I live in california"%

Thats strange. I am not doing anything related to FastAPI or uvicorn in my FlairTokenizer deployment. Code for this is adapted from Ray Serve: Ray Serve vs Regular Web server Performance? - #2 by jiaodong

Ah ok I see the issue. If httptools is present, the duplicate headers will happen. Because uvicorn will use the httptools implementation first uvicorn/auto.py at 0.16.0 Β· encode/uvicorn Β· GitHub.

I will file an issue: [Serve] Duplicate headers with httptools Β· Issue #21876 Β· ray-project/ray Β· GitHub

Current workaround is pip uninstall httptools (if possible.)

I uninstalled httptools from head and worker nodes, redeployed all the deployments. But still getting duplicate content-length.

@simon-mo , am I missing any steps here?

I will proceed with complete cluster removal and update if that works.

You might need to restart ray serve by serve.shutdown to restart the http process as well.

@lihost I created a PR to fix this: [Serve] Fix uvicorn duplicate header issue by simon-mo Β· Pull Request #21884 Β· ray-project/ray Β· GitHub

Thanks @simon-mo,

Meanwhile I reset complete cluster and ran another curl but no change. I am still seeing duplicate content-length.

BTW, I am exposing head node via port-forward to test curl call.

Also head and worker has below concerned packages

(base) ray@example-cluster-ray-head-type-scf2c:~$ pip list | grep -E "httptools|uvicorn|h11"
h11                                    0.13.0
uvicorn                                0.16.0

Hi @lihost,

if you run on linux, would you mind test out the fix? Here are the Python wheels that can directly be installed.

3.6
https://ray-ci-artifact-pr-public.s3.amazonaws.com/f911e61e9b21ab2e474d1813f9ee4430b5764146/tmp/artifacts/.whl/ray-2.0.0.dev0-cp36-cp36m-manylinux2014_x86_64.whl

3.7
https://ray-ci-artifact-pr-public.s3.amazonaws.com/f911e61e9b21ab2e474d1813f9ee4430b5764146/tmp/artifacts/.whl/ray-2.0.0.dev0-cp37-cp37m-manylinux2014_x86_64.whl

3.8
https://ray-ci-artifact-pr-public.s3.amazonaws.com/f911e61e9b21ab2e474d1813f9ee4430b5764146/tmp/artifacts/.whl/ray-2.0.0.dev0-cp38-cp38-manylinux2014_x86_64.whl

3.9
https://ray-ci-artifact-pr-public.s3.amazonaws.com/f911e61e9b21ab2e474d1813f9ee4430b5764146/tmp/artifacts/.whl/ray-2.0.0.dev0-cp39-cp39-manylinux2014_x86_64.whl

I would have tested this but my local machine is Macbook Pro. Not sure if there is any alternative to ray submit

Ah i believe you don’t need to upgrade the version on your laptop. Just the cluster side should be enough. You can keep using release ray on your laptop or install nightly wheel Installing Ray β€” Ray v1.9.2

I installed ray==v1.9.2. Got errors related to redis during ray submit(same code).

❯ pip list | grep ray
ray                       1.9.2

❯ ray submit example-full.yaml deploy_test.py
2022-01-25 20:02:30,121	INFO util.py:282 -- setting max workers for head node type to 0
Loaded cached provider configuration
If you experience issues with the cloud provider, try re-running the command with --no-config-cache.
2022-01-25 20:02:35,469	INFO util.py:282 -- setting max workers for head node type to 0
2022-01-25 20:02:35,557	INFO command_runner.py:172 -- NodeUpdater: example-cluster-ray-head-type-429zh: Running kubectl -n ray exec -it example-cluster-ray-head-type-429zh -- bash --login -c -i 'true && source ~/.bashrc && export OMP_NUM_THREADS=1 PYTHONWARNINGS=ignore && (python ~/deploy_test.py)'
Traceback (most recent call last):
  File "/home/ray/deploy_test.py", line 15, in <module>
    ray.init(address="auto", namespace="ray", log_to_driver=True, logging_level=logging.INFO)
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/_private/client_mode_hook.py", line 105, in wrapper
    return func(*args, **kwargs)
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/worker.py", line 961, in init
    connect_only=True)
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/node.py", line 177, in __init__
    "session_name", ray_constants.KV_NAMESPACE_SESSION)
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/node.py", line 1469, in _internal_kv_get_with_retry
    raise RuntimeError(f"Could not read '{key}' from GCS (redis). "
RuntimeError: Could not read 'b'session_name'' from GCS (redis). If using Redis, did Redis start successfully?
command terminated with exit code 1
2022-01-25 20:03:23,789	ERROR command_runner.py:182 -- NodeUpdater: example-cluster-ray-head-type-429zh: Command failed:

  kubectl -n ray exec -it example-cluster-ray-head-type-429zh --'bash --login -c -i '"'"'true && source ~/.bashrc && export OMP_NUM_THREADS=1 PYTHONWARNINGS=ignore && (python ~/deploy_test.py)'"'"''

How about nightlies? And make sure Ray is restarted?

Same errors.

❯ pip list | grep ray
ray                      2.0.0.dev0

❯ ray submit example-full.yaml deploy_test.py
2022-01-25 20:42:43,517	INFO util.py:282 -- setting max workers for head node type to 0
Loaded cached provider configuration
If you experience issues with the cloud provider, try re-running the command with --no-config-cache.
2022-01-25 20:42:48,367	INFO util.py:282 -- setting max workers for head node type to 0
2022-01-25 20:42:48,452	INFO command_runner.py:172 -- NodeUpdater: example-cluster-ray-head-type-429zh: Running kubectl -n ray exec -it example-cluster-ray-head-type-429zh -- bash --login -c -i 'true && source ~/.bashrc && export OMP_NUM_THREADS=1 PYTHONWARNINGS=ignore && (python ~/deploy_test.py)'
Traceback (most recent call last):
  File "/home/ray/deploy_test.py", line 15, in <module>
    ray.init(address="auto", namespace="ray", log_to_driver=True, logging_level=logging.INFO)
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/_private/client_mode_hook.py", line 105, in wrapper
    return func(*args, **kwargs)
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/worker.py", line 961, in init
    connect_only=True)
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/node.py", line 177, in __init__
    "session_name", ray_constants.KV_NAMESPACE_SESSION)
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/node.py", line 1469, in _internal_kv_get_with_retry
    raise RuntimeError(f"Could not read '{key}' from GCS (redis). "
RuntimeError: Could not read 'b'session_name'' from GCS (redis). If using Redis, did Redis start successfully?
command terminated with exit code 1
2022-01-25 20:43:32,171	ERROR command_runner.py:182 -- NodeUpdater: example-cluster-ray-head-type-429zh: Command failed:

  kubectl -n ray exec -it example-cluster-ray-head-type-429zh --'bash --login -c -i '"'"'true && source ~/.bashrc && export OMP_NUM_THREADS=1 PYTHONWARNINGS=ignore && (python ~/deploy_test.py)'"'"''

Hi @lihost, the PR was merged. You should be able to install the same version of nightly wheels that included the fix. The wheels should be produced in few hours and available via Installing Ray β€” Ray v1.9.2

You can verified it finding the new import ray; ray.__commit__ field include [Serve] Fix uvicorn duplicate header issue (#21884) Β· ray-project/ray@ac6709f Β· GitHub

Hi @simon-mo , thanks for update.

I deployed the same on all head and worker nodes as well as in my machine. I also confirmed the commit and ray status.

(base) ray@example-cluster-ray-worker-type-2vxjm:~$ python
Python 3.7.7 (default, May  7 2020, 21:25:33)
[GCC 7.3.0] :: Anaconda, Inc. on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import ray
>>> ray.__commit__
'ac6709f0ba0b6760979add194609a025a4689f3f'

  • ModuleNotFoundError: No module named 'aiorwlock' during submit.
❯ ray submit example-full.yaml deploy_test.py
2022-01-26 18:18:53,202	INFO util.py:278 -- setting max workers for head node type to 0
Loaded cached provider configuration
If you experience issues with the cloud provider, try re-running the command with --no-config-cache.
2022-01-26 18:18:58,171	INFO util.py:278 -- setting max workers for head node type to 0
2022-01-26 18:18:58,265	INFO command_runner.py:172 -- NodeUpdater: example-cluster-ray-head-type-429zh: Running kubectl -n ray exec -it example-cluster-ray-head-type-429zh -- bash --login -c -i 'true && source ~/.bashrc && export OMP_NUM_THREADS=1 PYTHONWARNINGS=ignore && (python ~/deploy_test.py)'
2022-01-26 18:19:02,114	INFO api.py:465 -- Connecting to existing Serve instance in namespace 'ray'.
2022-01-26 18:19:02,174	INFO api.py:259 -- Updating deployment 'APIWrapper'. component=serve deployment=APIWrapper
Traceback (most recent call last):
  File "/home/ray/deploy_test.py", line 75, in <module>
    APIWrapper.deploy()
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/serve/api.py", line 860, in deploy
    _blocking=_blocking)
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/serve/api.py", line 93, in check
    return f(self, *args, **kwargs)
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/serve/api.py", line 265, in deploy
    self._wait_for_goal(goal_id)
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/serve/api.py", line 192, in _wait_for_goal
    async_goal_exception = ray.get(ready)[0]
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/_private/client_mode_hook.py", line 105, in wrapper
    return func(*args, **kwargs)
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/worker.py", line 1763, in get
    raise value.as_instanceof_cause()
ray.exceptions.RayTaskError(ModuleNotFoundError): ray::ServeController.listen_for_change() (pid=4523, ip=172.18.37.107)
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/serve/utils.py", line 241, in wrap_to_ray_error
    raise exception
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/serve/deployment_state.py", line 1152, in update
    running_replicas_changed = self._scale_deployment_replicas()
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/serve/deployment_state.py", line 929, in _scale_deployment_replicas
    self._target_version)
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/serve/deployment_state.py", line 402, in start
    self._actor.start(deployment_info, version)
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/serve/deployment_state.py", line 189, in start
    self._actor_handle = deployment_info.actor_def.options(
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/serve/common.py", line 61, in actor_def
    from ray.serve.replica import create_replica_wrapper
  File "/home/ray/anaconda3/lib/python3.7/site-packages/ray/serve/replica.py", line 7, in <module>
    import aiorwlock
ModuleNotFoundError: No module named 'aiorwlock'
(ServeController pid=4523) 2022-01-26 18:19:02,270	INFO deployment_state.py:919 -- Adding 1 replicas to deployment 'APIWrapper'. component=serve deployment=APIWrapper
(ServeController pid=4523) 2022-01-26 18:19:02,271	INFO deployment_state.py:1188 -- Deployment 'APIWrapper' failed, deleting it. component=serve deployment=APIWrapper
command terminated with exit code 1
2022-01-26 18:19:03,691	ERROR command_runner.py:184 -- NodeUpdater: example-cluster-ray-head-type-429zh: Command failed:

  kubectl -n ray exec -it example-cluster-ray-head-type-429zh --'bash --login -c -i '"'"'true && source ~/.bashrc && export OMP_NUM_THREADS=1 PYTHONWARNINGS=ignore && (python ~/deploy_test.py)'"'"''

  • pip install aiorwlock has removed above error.