Skip to content

Commit 560f6ee

Browse files
aaugustinaaugustin
committed
Log error when server receives bad request.
1 parent 9605507 commit 560f6ee

File tree

5 files changed

+206
-140
lines changed

5 files changed

+206
-140
lines changed

‎src/websockets/asyncio/server.py

+80-75
Original file line numberDiff line numberDiff line change
@@ -138,81 +138,76 @@ async def handshake(
138138
Perform the opening handshake.
139139
140140
"""
141-
# May raise CancelledError if open_timeout is exceeded.
142141
await asyncio.wait(
143142
[self.request_rcvd, self.connection_lost_waiter],
144143
return_when=asyncio.FIRST_COMPLETED,
145144
)
146145

147-
if self.request is None:
148-
raise ConnectionError("connection closed during handshake")
149-
150-
async with self.send_context(expected_state=CONNECTING):
151-
response = None
152-
153-
if process_request is not None:
154-
try:
155-
response = process_request(self, self.request)
156-
if isinstance(response, Awaitable):
157-
response = await response
158-
except Exception as exc:
159-
self.protocol.handshake_exc = exc
160-
self.logger.error("opening handshake failed", exc_info=True)
161-
response = self.protocol.reject(
162-
http.HTTPStatus.INTERNAL_SERVER_ERROR,
163-
(
164-
"Failed to open a WebSocket connection.\n"
165-
"See server log for more information.\n"
166-
),
167-
)
168-
169-
if response is None:
170-
if self.server.is_serving():
171-
self.response = self.protocol.accept(self.request)
146+
if self.request is not None:
147+
async with self.send_context(expected_state=CONNECTING):
148+
response = None
149+
150+
if process_request is not None:
151+
try:
152+
response = process_request(self, self.request)
153+
if isinstance(response, Awaitable):
154+
response = await response
155+
except Exception as exc:
156+
self.protocol.handshake_exc = exc
157+
response = self.protocol.reject(
158+
http.HTTPStatus.INTERNAL_SERVER_ERROR,
159+
(
160+
"Failed to open a WebSocket connection.\n"
161+
"See server log for more information.\n"
162+
),
163+
)
164+
165+
if response is None:
166+
if self.server.is_serving():
167+
self.response = self.protocol.accept(self.request)
168+
else:
169+
self.response = self.protocol.reject(
170+
http.HTTPStatus.SERVICE_UNAVAILABLE,
171+
"Server is shutting down.\n",
172+
)
172173
else:
173-
self.response = self.protocol.reject(
174-
http.HTTPStatus.SERVICE_UNAVAILABLE,
175-
"Server is shutting down.\n",
176-
)
177-
else:
178-
assert isinstance(response, Response) # help mypy
179-
self.response = response
180-
181-
if server_header:
182-
self.response.headers["Server"] = server_header
183-
184-
response = None
185-
186-
if process_response is not None:
187-
try:
188-
response = process_response(self, self.request, self.response)
189-
if isinstance(response, Awaitable):
190-
response = await response
191-
except Exception as exc:
192-
self.protocol.handshake_exc = exc
193-
self.logger.error("opening handshake failed", exc_info=True)
194-
response = self.protocol.reject(
195-
http.HTTPStatus.INTERNAL_SERVER_ERROR,
196-
(
197-
"Failed to open a WebSocket connection.\n"
198-
"See server log for more information.\n"
199-
),
200-
)
201-
202-
if response is not None:
203-
assert isinstance(response, Response) # help mypy
204-
self.response = response
205-
206-
self.protocol.send_response(self.response)
174+
assert isinstance(response, Response) # help mypy
175+
self.response = response
176+
177+
if server_header:
178+
self.response.headers["Server"] = server_header
179+
180+
response = None
181+
182+
if process_response is not None:
183+
try:
184+
response = process_response(self, self.request, self.response)
185+
if isinstance(response, Awaitable):
186+
response = await response
187+
except Exception as exc:
188+
self.protocol.handshake_exc = exc
189+
response = self.protocol.reject(
190+
http.HTTPStatus.INTERNAL_SERVER_ERROR,
191+
(
192+
"Failed to open a WebSocket connection.\n"
193+
"See server log for more information.\n"
194+
),
195+
)
196+
197+
if response is not None:
198+
assert isinstance(response, Response) # help mypy
199+
self.response = response
200+
201+
self.protocol.send_response(self.response)
202+
203+
# self.protocol.handshake_exc is always set when the connection is lost
204+
# before receiving a request, when the request cannot be parsed, or when
205+
# the response fails the handshake.
207206

208207
if self.protocol.handshake_exc is None:
209208
self.start_keepalive()
210209
else:
211-
try:
212-
async with asyncio_timeout(self.close_timeout):
213-
await self.connection_lost_waiter
214-
finally:
215-
raise self.protocol.handshake_exc
210+
raise self.protocol.handshake_exc
216211

217212
def process_event(self, event: Event) -> None:
218213
"""
@@ -359,25 +354,35 @@ async def conn_handler(self, connection: ServerConnection) -> None:
359354
360355
"""
361356
try:
362-
# On failure, handshake() closes the transport, raises an
363-
# exception, and logs it.
364357
async with asyncio_timeout(self.open_timeout):
365-
await connection.handshake(
366-
self.process_request,
367-
self.process_response,
368-
self.server_header,
369-
)
358+
try:
359+
await connection.handshake(
360+
self.process_request,
361+
self.process_response,
362+
self.server_header,
363+
)
364+
except asyncio.CancelledError:
365+
connection.close_transport()
366+
raise
367+
except Exception:
368+
connection.logger.error("opening handshake failed", exc_info=True)
369+
connection.close_transport()
370+
return
370371

371372
try:
372373
await self.handler(connection)
373374
except Exception:
374-
self.logger.error("connection handler failed", exc_info=True)
375+
connection.logger.error("connection handler failed", exc_info=True)
375376
await connection.close(CloseCode.INTERNAL_ERROR)
376377
else:
377378
await connection.close()
378379

379-
except Exception:
380-
# Don't leak connections on errors.
380+
except TimeoutError:
381+
# When the opening handshake times out, there's nothing to log.
382+
pass
383+
384+
except Exception: # pragma: no cover
385+
# Don't leak connections on unexpected errors.
381386
connection.transport.abort()
382387

383388
finally:

‎src/websockets/sync/server.py

+72-64
Original file line numberDiff line numberDiff line change
@@ -23,7 +23,7 @@
2323
validate_subprotocols,
2424
)
2525
from ..http11 import SERVER, Request, Response
26-
from ..protocol import CONNECTING, OPEN, Event
26+
from ..protocol import CONNECTING, Event
2727
from ..server import ServerProtocol
2828
from ..typing import LoggerLike, Origin, StatusLike, Subprotocol
2929
from .connection import Connection
@@ -118,61 +118,56 @@ def handshake(
118118
119119
"""
120120
if not self.request_rcvd.wait(timeout):
121-
self.close_socket()
122-
self.recv_events_thread.join()
123121
raise TimeoutError("timed out during handshake")
124122

125-
if self.request is None:
126-
self.close_socket()
127-
self.recv_events_thread.join()
128-
raise ConnectionError("connection closed during handshake")
129-
130-
with self.send_context(expected_state=CONNECTING):
131-
self.response = None
132-
133-
if process_request is not None:
134-
try:
135-
self.response = process_request(self, self.request)
136-
except Exception as exc:
137-
self.protocol.handshake_exc = exc
138-
self.logger.error("opening handshake failed", exc_info=True)
139-
self.response = self.protocol.reject(
140-
http.HTTPStatus.INTERNAL_SERVER_ERROR,
141-
(
142-
"Failed to open a WebSocket connection.\n"
143-
"See server log for more information.\n"
144-
),
145-
)
146-
147-
if self.response is None:
148-
self.response = self.protocol.accept(self.request)
149-
150-
if server_header:
151-
self.response.headers["Server"] = server_header
152-
153-
if process_response is not None:
154-
try:
155-
response = process_response(self, self.request, self.response)
156-
except Exception as exc:
157-
self.protocol.handshake_exc = exc
158-
self.logger.error("opening handshake failed", exc_info=True)
159-
self.response = self.protocol.reject(
160-
http.HTTPStatus.INTERNAL_SERVER_ERROR,
161-
(
162-
"Failed to open a WebSocket connection.\n"
163-
"See server log for more information.\n"
164-
),
165-
)
123+
if self.request is not None:
124+
with self.send_context(expected_state=CONNECTING):
125+
response = None
126+
127+
if process_request is not None:
128+
try:
129+
response = process_request(self, self.request)
130+
except Exception as exc:
131+
self.protocol.handshake_exc = exc
132+
response = self.protocol.reject(
133+
http.HTTPStatus.INTERNAL_SERVER_ERROR,
134+
(
135+
"Failed to open a WebSocket connection.\n"
136+
"See server log for more information.\n"
137+
),
138+
)
139+
140+
if response is None:
141+
self.response = self.protocol.accept(self.request)
166142
else:
143+
self.response = response
144+
145+
if server_header:
146+
self.response.headers["Server"] = server_header
147+
148+
response = None
149+
150+
if process_response is not None:
151+
try:
152+
response = process_response(self, self.request, self.response)
153+
except Exception as exc:
154+
self.protocol.handshake_exc = exc
155+
response = self.protocol.reject(
156+
http.HTTPStatus.INTERNAL_SERVER_ERROR,
157+
(
158+
"Failed to open a WebSocket connection.\n"
159+
"See server log for more information.\n"
160+
),
161+
)
162+
167163
if response is not None:
168164
self.response = response
169165

170-
self.protocol.send_response(self.response)
166+
self.protocol.send_response(self.response)
171167

172-
if self.protocol.state is not OPEN:
173-
self.recv_events_thread.join(self.close_timeout)
174-
self.close_socket()
175-
self.recv_events_thread.join()
168+
# self.protocol.handshake_exc is always set when the connection is lost
169+
# before receiving a request, when the request cannot be parsed, or when
170+
# the response fails the handshake.
176171

177172
if self.protocol.handshake_exc is not None:
178173
raise self.protocol.handshake_exc
@@ -552,26 +547,39 @@ def protocol_select_subprotocol(
552547
protocol,
553548
close_timeout=close_timeout,
554549
)
555-
# On failure, handshake() closes the socket, raises an exception, and
556-
# logs it.
557-
connection.handshake(
558-
process_request,
559-
process_response,
560-
server_header,
561-
deadline.timeout(),
562-
)
563-
564550
except Exception:
565551
sock.close()
566552
return
567553

568554
try:
569-
handler(connection)
570-
except Exception:
571-
protocol.logger.error("connection handler failed", exc_info=True)
572-
connection.close(CloseCode.INTERNAL_ERROR)
573-
else:
574-
connection.close()
555+
try:
556+
connection.handshake(
557+
process_request,
558+
process_response,
559+
server_header,
560+
deadline.timeout(),
561+
)
562+
except TimeoutError:
563+
connection.close_socket()
564+
connection.recv_events_thread.join()
565+
return
566+
except Exception:
567+
connection.logger.error("opening handshake failed", exc_info=True)
568+
connection.close_socket()
569+
connection.recv_events_thread.join()
570+
return
571+
572+
try:
573+
handler(connection)
574+
except Exception:
575+
connection.logger.error("connection handler failed", exc_info=True)
576+
connection.close(CloseCode.INTERNAL_ERROR)
577+
else:
578+
connection.close()
579+
580+
except Exception: # pragma: no cover
581+
# Don't leak sockets on unexpected errors.
582+
sock.close()
575583

576584
# Initialize server
577585

‎tests/asyncio/test_server.py

+21
Original file line numberDiff line numberDiff line change
@@ -406,6 +406,27 @@ async def test_connection_closed_during_handshake(self):
406406
_reader, writer = await asyncio.open_connection(*get_host_port(server))
407407
writer.close()
408408

409+
async def test_junk_handshake(self):
410+
"""Server closes the connection when receiving non-HTTP request from client."""
411+
with self.assertLogs("websockets", logging.ERROR) as logs:
412+
async with serve(*args) as server:
413+
reader, writer = await asyncio.open_connection(*get_host_port(server))
414+
writer.write(b"HELO relay.invalid\r\n")
415+
try:
416+
# Wait for the server to close the connection.
417+
self.assertEqual(await reader.read(4096), b"")
418+
finally:
419+
writer.close()
420+
421+
self.assertEqual(
422+
[record.getMessage() for record in logs.records],
423+
["opening handshake failed"],
424+
)
425+
self.assertEqual(
426+
[str(record.exc_info[1]) for record in logs.records],
427+
["invalid HTTP request line: HELO relay.invalid"],
428+
)
429+
409430
async def test_close_server_rejects_connecting_connections(self):
410431
"""Server rejects connecting connections with HTTP 503 when closing."""
411432

0 commit comments

Comments
 (0)