Skip to content
This repository has been archived by the owner on Apr 26, 2024. It is now read-only.

Downgrade warning on client disconnect to INFO #7928

Merged
merged 3 commits into from
Jul 24, 2020
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions changelog.d/7928.misc
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
When a client disconnects, don't log it as 'Error processing request'.
4 changes: 1 addition & 3 deletions synapse/http/site.py
Original file line number Diff line number Diff line change
Expand Up @@ -215,9 +215,7 @@ def connectionLost(self, reason):
# It's useful to log it here so that we can get an idea of when
# the client disconnects.
with PreserveLoggingContext(self.logcontext):
logger.warning(
"Error processing request %r: %s %s", self, reason.type, reason.value
)
logger.info("Connection from client lost before response was sent")

if not self._is_processing:
self._finished_processing()
Expand Down
59 changes: 1 addition & 58 deletions tests/test_server.py
Original file line number Diff line number Diff line change
Expand Up @@ -12,26 +12,20 @@
# See the License for the specific language governing permissions and
# limitations under the License.

import logging
import re
from io import StringIO

from twisted.internet.defer import Deferred
from twisted.python.failure import Failure
from twisted.test.proto_helpers import AccumulatingProtocol
from twisted.web.resource import Resource
from twisted.web.server import NOT_DONE_YET

from synapse.api.errors import Codes, RedirectException, SynapseError
from synapse.config.server import parse_listener_def
from synapse.http.server import DirectServeHtmlResource, JsonResource, OptionsResource
from synapse.http.site import SynapseSite, logger
from synapse.http.site import SynapseSite
from synapse.logging.context import make_deferred_yieldable
from synapse.util import Clock

from tests import unittest
from tests.server import (
FakeTransport,
ThreadedMemoryReactorClock,
make_request,
render,
Expand Down Expand Up @@ -318,54 +312,3 @@ def callback(request, **kwargs):
self.assertEqual(location_headers, [b"/no/over/there"])
cookies_headers = [v for k, v in headers if k == b"Set-Cookie"]
self.assertEqual(cookies_headers, [b"session=yespls"])


class SiteTestCase(unittest.HomeserverTestCase):
def test_lose_connection(self):
"""
We log the URI correctly redacted when we lose the connection.
"""

class HangingResource(Resource):
"""
A Resource that strategically hangs, as if it were processing an
answer.
"""

def render(self, request):
return NOT_DONE_YET

# Set up a logging handler that we can inspect afterwards
output = StringIO()
handler = logging.StreamHandler(output)
logger.addHandler(handler)
old_level = logger.level
logger.setLevel(10)
self.addCleanup(logger.setLevel, old_level)
self.addCleanup(logger.removeHandler, handler)

# Make a resource and a Site, the resource will hang and allow us to
# time out the request while it's 'processing'
base_resource = Resource()
base_resource.putChild(b"", HangingResource())
site = SynapseSite(
"test", "site_tag", self.hs.config.listeners[0], base_resource, "1.0"
)

server = site.buildProtocol(None)
client = AccumulatingProtocol()
client.makeConnection(FakeTransport(server, self.reactor))
server.makeConnection(FakeTransport(client, self.reactor))

# Send a request with an access token that will get redacted
server.dataReceived(b"GET /?access_token=bar HTTP/1.0\r\n\r\n")
self.pump()

# Lose the connection
e = Failure(Exception("Failed123"))
server.connectionLost(e)
handler.flush()

# Our access token is redacted and the failure reason is logged.
self.assertIn("/?access_token=<redacted>", output.getvalue())
self.assertIn("Failed123", output.getvalue())