Skip to content

Commit

Permalink
Log first occurrence of bad request errors at level ERROR for higher …
Browse files Browse the repository at this point in the history
…visibility
  • Loading branch information
miguelgrinberg committed Nov 29, 2020
1 parent c29dfc3 commit 3fc702f
Show file tree
Hide file tree
Showing 3 changed files with 51 additions and 18 deletions.
25 changes: 16 additions & 9 deletions engineio/asyncio_server.py
Original file line number Diff line number Diff line change
Expand Up @@ -199,7 +199,8 @@ async def handle_request(self, *args, **kwargs):
allowed_origins = self._cors_allowed_origins(environ)
if allowed_origins is not None and origin not in \
allowed_origins:
self.logger.info(origin + ' is not an accepted origin.')
self._log_error_once(
origin + ' is not an accepted origin.', 'bad-origin')
return await self._make_response(
self._bad_request(
origin + ' is not an accepted origin.'),
Expand All @@ -216,6 +217,10 @@ async def handle_request(self, *args, **kwargs):
# make sure the client speaks a compatible Engine.IO version
sid = query['sid'][0] if 'sid' in query else None
if sid is None and query.get('EIO') not in [['2'], ['3']]:
self._log_error_once(
'The client is using an unsupported version of the Socket.IO '
'or Engine.IO protocols', 'bad-version'
)
return await self._make_response(self._bad_request(
'The client is using an unsupported version of the Socket.IO '
'or Engine.IO protocols'
Expand All @@ -233,23 +238,25 @@ async def handle_request(self, *args, **kwargs):
pass

if jsonp and jsonp_index is None:
self.logger.warning('Invalid JSONP index number')
r = self._bad_request()
self._log_error_once('Invalid JSONP index number',
'bad-jsonp-index')
r = self._bad_request('Invalid JSONP index number')
elif method == 'GET':
if sid is None:
transport = query.get('transport', ['polling'])[0]
if (transport != 'polling' and transport != 'websocket') or \
(transport != 'polling'
and transport != environ.get('HTTP_UPGRADE')):
self.logger.warning('Invalid transport %s', transport)
r = self._bad_request()
self._log_error_once('Invalid transport ' + transport,
'bad-transport')
r = self._bad_request('Invalid transport ' + transport)
else:
r = await self._handle_connect(environ, transport,
b64, jsonp_index)
else:
if sid not in self.sockets:
self.logger.warning('Invalid session %s', sid)
r = self._bad_request()
self._log_error_once('Invalid session ' + sid, 'bad-sid')
r = self._bad_request('Invalid session ' + sid)
else:
socket = self._get_socket(sid)
try:
Expand All @@ -267,8 +274,8 @@ async def handle_request(self, *args, **kwargs):
del self.sockets[sid]
elif method == 'POST':
if sid is None or sid not in self.sockets:
self.logger.warning('Invalid session %s', sid)
r = self._bad_request()
self._log_error_once('Invalid session ' + sid, 'bad-sid')
r = self._bad_request('Invalid session ' + sid)
else:
socket = self._get_socket(sid)
try:
Expand Down
35 changes: 26 additions & 9 deletions engineio/server.py
Original file line number Diff line number Diff line change
Expand Up @@ -109,6 +109,7 @@ def __init__(self, async_mode=None, ping_timeout=60, ping_interval=25,
self.async_handlers = async_handlers
self.sockets = {}
self.handlers = {}
self.log_message_keys = set()
self.start_service_task = monitor_clients \
if monitor_clients is not None else self._default_monitor_clients
if json is not None:
Expand Down Expand Up @@ -335,7 +336,8 @@ def handle_request(self, environ, start_response):
allowed_origins = self._cors_allowed_origins(environ)
if allowed_origins is not None and origin not in \
allowed_origins:
self.logger.info(origin + ' is not an accepted origin.')
self._log_error_once(
origin + ' is not an accepted origin.', 'bad-origin')
r = self._bad_request(
origin + ' is not an accepted origin.')
start_response(r['status'], r['headers'])
Expand All @@ -350,6 +352,9 @@ def handle_request(self, environ, start_response):
# make sure the client speaks a compatible Engine.IO version
sid = query['sid'][0] if 'sid' in query else None
if sid is None and query.get('EIO') not in [['2'], ['3']]:
self._log_error_once(
'The client is using an unsupported version of the Socket.IO '
'or Engine.IO protocols', 'bad-version')
r = self._bad_request(
'The client is using an unsupported version of the Socket.IO '
'or Engine.IO protocols')
Expand All @@ -368,23 +373,25 @@ def handle_request(self, environ, start_response):
pass

if jsonp and jsonp_index is None:
self.logger.warning('Invalid JSONP index number')
r = self._bad_request()
self._log_error_once('Invalid JSONP index number',
'bad-jsonp-index')
r = self._bad_request('Invalid JSONP index number')
elif method == 'GET':
if sid is None:
transport = query.get('transport', ['polling'])[0]
if (transport != 'polling' and transport != 'websocket') or \
(transport != 'polling'
and transport != environ.get('HTTP_UPGRADE')):
self.logger.warning('Invalid transport %s', transport)
r = self._bad_request()
self._log_error_once('Invalid transport ' + transport,
'bad-transport')
r = self._bad_request('Invalid transport ' + transport)
else:
r = self._handle_connect(environ, start_response,
transport, b64, jsonp_index)
else:
if sid not in self.sockets:
self.logger.warning('Invalid session %s', sid)
r = self._bad_request()
self._log_error_once('Invalid session ' + sid, 'bad-sid')
r = self._bad_request('Invalid session ' + sid)
else:
socket = self._get_socket(sid)
try:
Expand All @@ -403,8 +410,8 @@ def handle_request(self, environ, start_response):
del self.sockets[sid]
elif method == 'POST':
if sid is None or sid not in self.sockets:
self.logger.warning('Invalid session %s', sid)
r = self._bad_request()
self._log_error_once('Invalid session ' + sid, 'bad-sid')
r = self._bad_request('Invalid session ' + sid)
else:
socket = self._get_socket(sid)
try:
Expand Down Expand Up @@ -697,6 +704,16 @@ def _deflate(self, response):
"""Apply deflate compression to a response."""
return zlib.compress(response)

def _log_error_once(self, message, message_key):
"""Log message with logging.ERROR level the first time, then log
with given level."""
if message_key not in self.log_message_keys:
self.logger.error(message + ' (further occurrences of this error '
'will be logged with level INFO)')
self.log_message_keys.add(message_key)
else:
self.logger.info(message)

def _service_task(self): # pragma: no cover
"""Monitor connected clients and clean up those that time out."""
while True:
Expand Down
9 changes: 9 additions & 0 deletions tests/common/test_server.py
Original file line number Diff line number Diff line change
Expand Up @@ -1160,6 +1160,15 @@ def test_create_event(self):
e.set()
assert e.is_set()

def test_log_error_once(self):
s = server.Server(logger=mock.MagicMock())
s._log_error_once('foo', 'foo-key')
s._log_error_once('foo', 'foo-key')
s.logger.error.assert_called_with(
'foo (further occurrences of this error will be logged with '
'level INFO)')
s.logger.info.assert_called_with('foo')

def test_service_task_started(self):
s = server.Server(monitor_clients=True)
s._service_task = mock.MagicMock()
Expand Down

0 comments on commit 3fc702f

Please sign in to comment.