[Bug]: "Address already in use" for 1 minute after crash (since 0.6.2)

[hibukipanim]

🐛 Describe the bug

Since version 0.6.2 (happens also in 0.6.3.post1), after the server dies (due to an exception/crash or hitting ctrl-c), for about a minute, it fails to start again with:

Traceback (most recent call last):
  File "/usr/lib/python3.10/runpy.py", line 196, in _run_module_as_main
    return _run_code(code, main_globals, None,
  File "/usr/lib/python3.10/runpy.py", line 86, in _run_code
    exec(code, run_globals)
  File "/home/user/code/debug/.venv/lib/python3.10/site-packages/vllm/entrypoints/openai/api_server.py", line 585, in <module>
    uvloop.run(run_server(args))
  File "/home/user/code/debug/.venv/lib/python3.10/site-packages/uvloop/__init__.py", line 82, in run
    return loop.run_until_complete(wrapper())
  File "uvloop/loop.pyx", line 1517, in uvloop.loop.Loop.run_until_complete
  File "/home/user/code/debug/.venv/lib/python3.10/site-packages/uvloop/__init__.py", line 61, in wrapper
    return await main
  File "/home/user/code/debug/.venv/lib/python3.10/site-packages/vllm/entrypoints/openai/api_server.py", line 544, in run_server
    sock.bind(("", args.port))
OSError: [Errno 98] Address already in use

This prolongs recovery from crashes. In example upon crash Kubernetes immediately restarts the container - previously it would immediately start loading the model again, but now it will do several crash/restart loops until the port is freed.

Verified it happens also with --disable-frontend-multiprocessing.

To reproduce it, start vllm with default args, in example:

python -m vllm.entrypoints.openai.api_server --model TinyLlama/TinyLlama-1.1B-Chat-v1.0

and then send at least one chat or completion request to it (without this it won't reproduce).
then hit Ctrl-C to kill the server.
starting vllm again should throw the "Address already in use" error.
This doesn't happen with vllm <= 0.6.1.

I tried to see why the port is busy, and interestingly the vllm process is dead during this ~1 minute and no other process listens on it. However I noticed that there is a socket open from the 8000 port. Can see it via:

netstat | grep  ':8000'

which would show something like:

tcp        0      0 localhost:8000          localhost:40452         TIME_WAIT   -
tcp        0      0 localhost:8000          localhost:56324         TIME_WAIT   -
tcp        0      0 localhost:8000          localhost:40466         TIME_WAIT   -

After a minute these entries will disappear and then also vllm will manage to start.
I couldn't attribute it to a PID, nor with various nestat or lsof flags. Maybe it remains open in the kernel due to unclean process exit?

[yansh97]

I encountered the same issue, but it seems to only occur in the Docker container. I haven’t experienced this issue on the bare server.

[hibukipanim]

@yansh97 👍
In the description above I reproduce it also by running locally the pip package in WSL (and it also happens in Kubernetes, not in WSL)

[pseudotensor]

Ya ever since some version, maybe 0.6.1 or so, always see this, constant problem, eventually in docker with restart always it comes up, but annoying.

[russellb]

The original report says

(due to an exception/crash or hitting ctrl-c)

Can someone confirm they see this with ctrl-c (not in docker) ? In my testing with exiting that way, the process cleans up properly before exiting.

I'm guessing this is happening when vllm is not given a chance to exit cleanly. Can you clarify exactly how you're running vllm and exiting?

[pseudotensor]

Issue is not exit cleanly, first time docker comes up, fails randomly with this and repeats about 5-15 times before finally coming up.

I think it's a race inside vLLM itself.

[yansh97]

The original report says 原始报告说

(due to an exception/crash or hitting ctrl-c)（由于异常/崩溃或按 Ctrl-C）

Can someone confirm they see this with ctrl-c (not in docker) ? In my testing with exiting that way, the process cleans up properly before exiting.有人可以确认他们使用 ctrl-c（不在 docker 中）看到这一点吗？在我以这种方式退出的测试中，该过程在退出之前正确清理。

I'm guessing this is happening when vllm is not given a chance to exit cleanly. Can you clarify exactly how you're running vllm and exiting?我猜这是在没有机会干净地退出时发生的。您能澄清一下您是如何运行 vllm 和退出的吗？

I’ve only encountered this issue inside a Docker container. The ways to exit include pressing Ctrl+C, sending SIGINT or SIGTERM to the process from outside, or sending SIGINT or SIGTERM to itself within the Python code.

[wakk]

can I use sock.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1) reused address to solve the problem ?

    sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
    sock.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
    sock.bind(("", args.port))

[hibukipanim]

@russellb to double-check, did you send at least one chat completion request to the server before killing it with ctrl-c? it is required to reproduce 🙏

[russellb]

@russellb to double-check, did you send at least one chat completion request to the server before killing it with ctrl-c? it is required to reproduce 🙏

I did, yes, using curl

[hibukipanim]

@russellb I also couldn't reproduce it with curl now! so seems it is related to the client also. I managed to reproduce again with both openai client and also with requests, with the interesting bit that the client process should keep running after the request. As requests has less magic going-on, here is how I managed to reproduce it using it:

start the vllm server with:

 python -m vllm.entrypoints.openai.api_server --model TinyLlama/TinyLlama-1.1B-Chat-v1.0

then run this python script:

import requests
import time

url = "http://localhost:8000/v1/chat/completions"
data = {
    "model": "TinyLlama/TinyLlama-1.1B-Chat-v1.0",
    "messages": [{"role": "user", "content": "hello"}],
}
res = requests.post(url, json=data)
print(res.json()['choices'][0]['message'])

print("\nsleeping.. try killing vllm now and starting it again")
time.sleep(60)

then while the client is running (few seconds after the chat request), kill the vllm server with ctrl-c, and try starting vllm again (which should now fail with OSError: [Errno 98] Address already in use).
And during the first minute can still see the outgoing connection from port 8000 in netstat:
netstat | grep ':8000':

tcp        0      0 localhost:8000          localhost:42454         FIN_WAIT2

(I also noticed that the client process doesn't have to stay up for the whole minute, it's enough to wait few seconds until the connection in netstat shows FIN_WAIT2 - then even if it's killed, the vlllm server still would fail to use the port during the first minute)

Thanks for looking into it! 🙏

[russellb]

@russellb I also couldn't reproduce it with curl now! so seems it is related to the client also. I managed to reproduce again with both openai client and also with requests, with the interesting bit that the client process should keep running after the request. As requests has less magic going-on, here is how I managed to reproduce it using it:

In this case I think requests is not closing the connection. Try this change to your script:

#with requests.post(url, json=data) as res:
#    print(res.json()['choices'][0]['message'])

with requests.session() as s:
    s.headers['Connection'] = 'close'
    res = s.post(url, json=data)
    print(res.json()['choices'][0]['message'])

With that change, I don't see a connection hanging open.

[hibukipanim]

It is reproducing for me despite this change above 🤔 (as long as the client process stays up for few seconds)

I think it's very common scenario that the clients are still up when the server is crashing/exiting. This is also the default behavior of the openai client - it's actually recommended in the openai docs to create a client object once and then reuse it for multiple chat requests (but don't know if internally it keeps sockets up or not).
e.g. this also reproduces it:

import openai
import time

client = openai.OpenAI(
    base_url="http://localhost:8000/v1",
    api_key="foo"
)

response = client.chat.completions.create(
    model="TinyLlama/TinyLlama-1.1B-Chat-v1.0",
    messages=[{"role": "user", "content": "hello"}],
)
print(response.choices[0].message)
time.sleep(5)

The client is not listening on the 8000 port, so I don't see why would the server fail to listen on it again after restart. And this didn't happen before 0.6.2.