log statement throws TypeError: can only concatenate str (not "NoneType") to str

gthb commented 1 week ago

Describe the bug

In async_server.handle_request, the POST case does this:

        elif method == 'POST':
            if sid is None or sid not in self.sockets:
                self._log_error_once('Invalid session ' + sid, 'bad-sid')
                r = self._bad_request('Invalid session ' + sid)

but in the sid is None case, this will always raise a TypeError (before calling self._log_error_once) saying “can only concatenate str (not "NoneType") to str”, resulting in a 500 Internal Server response being sent, instead of the obviously intended 400 Bad Request response.

To Reproduce

Send to an AsyncServer (in our case in uvicorn 0.20.0) a POST request with a query string containing EIO=4 and no sid query parameter, for example POST /socket.io5/?EIO=4&transport=websocket HTTP/1.1.

This error is raised:

TypeError: can only concatenate str (not "NoneType") to str
  File "uvicorn/protocols/http/httptools_impl.py", line 419, in run_asgi
    result = await app(  # type: ignore[func-returns-value]
  File "uvicorn/middleware/proxy_headers.py", line 78, in __call__
    return await self.app(scope, receive, send)
  File "uvicorn/middleware/message_logger.py", line 86, in __call__
    raise exc from None
  File "uvicorn/middleware/message_logger.py", line 82, in __call__
    await self.app(scope, inner_receive, inner_send)
  File "engineio/async_drivers/asgi.py", line 58, in __call__
    await self.engineio_server.handle_request(scope, receive, send)
  File "socketio/async_server.py", line 448, in handle_request
    return await self.eio.handle_request(*args, **kwargs)
  File "engineio/async_server.py", line 301, in handle_request
    self._log_error_once('Invalid session ' + sid, 'bad-sid')

The resulting behavior is that a 500 Internal Server Error response is sent.

Expected behavior

A 400 Bad Request response should be sent.

Logs

{
  "message": "Exception in ASGI application\n",
  "exc_info": "Traceback (most recent call last):\n  File \"/Users/gthb/Library/Caches/pypoetry/virtualenvs/grid-ONCl218o-py3.11/lib/python3.11/site-packages/uvicorn/protocols/http/httptools_impl.py\", line 419, in run_asgi\n    result = await app(  # type: ignore[func-returns-value]\n             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n  File \"/Users/gthb/Library/Caches/pypoetry/virtualenvs/grid-ONCl218o-py3.11/lib/python3.11/site-packages/uvicorn/middleware/proxy_headers.py\", line 78, in __call__\n    return await self.app(scope, receive, send)\n           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n  File \"/Users/gthb/Library/Caches/pypoetry/virtualenvs/grid-ONCl218o-py3.11/lib/python3.11/site-packages/uvicorn/middleware/message_logger.py\", line 86, in __call__\n    raise exc from None\n  File \"/Users/gthb/Library/Caches/pypoetry/virtualenvs/grid-ONCl218o-py3.11/lib/python3.11/site-packages/uvicorn/middleware/message_logger.py\", line 82, in __call__\n    await self.app(scope, inner_receive, inner_send)\n  File \"/Users/gthb/Library/Caches/pypoetry/virtualenvs/grid-ONCl218o-py3.11/lib/python3.11/site-packages/engineio/async_drivers/asgi.py\", line 58, in __call__\n    await self.engineio_server.handle_request(scope, receive, send)\n  File \"/Users/gthb/Library/Caches/pypoetry/virtualenvs/grid-ONCl218o-py3.11/lib/python3.11/site-packages/socketio/async_server.py\", line 448, in handle_request\n    return await self.eio.handle_request(*args, **kwargs)\n           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n  File \"/Users/gthb/Library/Caches/pypoetry/virtualenvs/grid-ONCl218o-py3.11/lib/python3.11/site-packages/engineio/async_server.py\", line 301, in handle_request\n    self._log_error_once('Invalid session ' + sid, 'bad-sid')\n                         ~~~~~~~~~~~~~~~~~~~^~~~~\nTypeError: can only concatenate str (not \"NoneType\") to str",
  "timestamp": "2024-10-14T15:09:27.075",
  "app_version": "local",
  "release_stage": "unknown",
  "logger_name": "uvicorn.error",
  "log_level": "ERROR"
}
{
  "message": "127.0.0.1:63416 - \"POST /socket.io5/?EIO=4&transport=websocket HTTP/1.1\" 500",
  "timestamp": "2024-10-14T15:09:27.078",
  "app_version": "local",
  "release_stage": "unknown",
  "logger_name": "uvicorn.access",
  "log_level": "INFO"
}
{
  "message": "/Users/gthb/Library/Caches/pypoetry/virtualenvs/grid-ONCl218o-py3.11/lib/python3.11/site-packages/coredis/connection.py:489: UserWarning: The server responded with no support for the `HELLO` command and therefore a handshake could not be performed\n  warnings.warn(warning, category=UserWarning)\n",
  "timestamp": "2024-10-14T15:09:31.855",
  "app_version": "local",
  "release_stage": "unknown",
  "logger_name": "py.warnings",
  "log_level": "WARNING"
}

miguelgrinberg commented 1 week ago

Sounds good, I'll fix it, but your Socket.IO client is faulty if it is sending POST request without a sid.

gthb commented 1 week ago

Sounds good, I'll fix it, but your Socket.IO client is faulty if it is sending POST request without a sid.

It sure is :) — addressing that, but obviously out of scope here.

miguelgrinberg / python-engineio

log statement throws TypeError: can only concatenate str (not "NoneType") to str #378