synapse/tests/handlers/test_receipts.py
Eric Eastwood 5a9ca1e3d9
Introduce Clock.call_when_running(...) to include logcontext by default (#18944)
Introduce `Clock.call_when_running(...)` to wrap startup code in a
logcontext, ensuring we can identify which server generated the logs.

Background:

>  Ideally, nothing from the Synapse homeserver would be logged against the `sentinel` 
>  logcontext as we want to know which server the logs came from. In practice, this is not 
>  always the case yet especially outside of request handling. 
>   
>  Global things outside of Synapse (e.g. Twisted reactor code) should run in the 
>  `sentinel` logcontext. It's only when it calls into application code that a logcontext 
>  gets activated. This means the reactor should be started in the `sentinel` logcontext, 
>  and any time an awaitable yields control back to the reactor, it should reset the 
>  logcontext to be the `sentinel` logcontext. This is important to avoid leaking the 
>  current logcontext to the reactor (which would then get picked up and associated with 
>  the next thing the reactor does). 
>
> *-- `docs/log_contexts.md`

Also adds a lint to prefer `Clock.call_when_running(...)` over
`reactor.callWhenRunning(...)`

Part of https://github.com/element-hq/synapse/issues/18905
2025-09-22 10:27:59 -05:00

344 lines
12 KiB
Python

#
# This file is licensed under the Affero General Public License (AGPL) version 3.
#
# Copyright 2021 Šimon Brandner <simon.bra.ag@gmail.com>
# Copyright (C) 2023 New Vector, Ltd
#
# This program is free software: you can redistribute it and/or modify
# it under the terms of the GNU Affero General Public License as
# published by the Free Software Foundation, either version 3 of the
# License, or (at your option) any later version.
#
# See the GNU Affero General Public License for more details:
# <https://www.gnu.org/licenses/agpl-3.0.html>.
#
# Originally licensed under the Apache License, Version 2.0:
# <http://www.apache.org/licenses/LICENSE-2.0>.
#
# [This file includes modifications made by New Vector Limited]
#
#
from copy import deepcopy
from typing import List
from twisted.internet.testing import MemoryReactor
from synapse.api.constants import EduTypes, ReceiptTypes
from synapse.server import HomeServer
from synapse.types import JsonDict
from synapse.util.clock import Clock
from tests import unittest
class ReceiptsTestCase(unittest.HomeserverTestCase):
def prepare(self, reactor: MemoryReactor, clock: Clock, hs: HomeServer) -> None:
self.event_source = hs.get_event_sources().sources.receipt
def test_filters_out_private_receipt(self) -> None:
self._test_filters_private(
[
{
"content": {
"$1435641916114394fHBLK:matrix.org": {
ReceiptTypes.READ_PRIVATE: {
"@rikj:jki.re": {
"ts": 1436451550453,
}
}
}
},
"room_id": "!jEsUZKDJdhlrceRyVU:example.org",
"type": EduTypes.RECEIPT,
}
],
[],
)
def test_filters_out_private_receipt_and_ignores_rest(self) -> None:
self._test_filters_private(
[
{
"content": {
"$1dgdgrd5641916114394fHBLK:matrix.org": {
ReceiptTypes.READ_PRIVATE: {
"@rikj:jki.re": {
"ts": 1436451550453,
},
},
ReceiptTypes.READ: {
"@user:jki.re": {
"ts": 1436451550453,
},
},
},
},
"room_id": "!jEsUZKDJdhlrceRyVU:example.org",
"type": EduTypes.RECEIPT,
}
],
[
{
"content": {
"$1dgdgrd5641916114394fHBLK:matrix.org": {
ReceiptTypes.READ: {
"@user:jki.re": {
"ts": 1436451550453,
}
}
}
},
"room_id": "!jEsUZKDJdhlrceRyVU:example.org",
"type": EduTypes.RECEIPT,
}
],
)
def test_filters_out_event_with_only_private_receipts_and_ignores_the_rest(
self,
) -> None:
self._test_filters_private(
[
{
"content": {
"$14356419edgd14394fHBLK:matrix.org": {
ReceiptTypes.READ_PRIVATE: {
"@rikj:jki.re": {
"ts": 1436451550453,
},
}
},
"$1435641916114394fHBLK:matrix.org": {
ReceiptTypes.READ: {
"@user:jki.re": {
"ts": 1436451550453,
}
}
},
},
"room_id": "!jEsUZKDJdhlrceRyVU:example.org",
"type": EduTypes.RECEIPT,
}
],
[
{
"content": {
"$1435641916114394fHBLK:matrix.org": {
ReceiptTypes.READ: {
"@user:jki.re": {
"ts": 1436451550453,
}
}
}
},
"room_id": "!jEsUZKDJdhlrceRyVU:example.org",
"type": EduTypes.RECEIPT,
}
],
)
def test_handles_empty_event(self) -> None:
self._test_filters_private(
[
{
"content": {
"$143564gdfg6114394fHBLK:matrix.org": {},
"$1435641916114394fHBLK:matrix.org": {
ReceiptTypes.READ: {
"@user:jki.re": {
"ts": 1436451550453,
}
}
},
},
"room_id": "!jEsUZKDJdhlrceRyVU:example.org",
"type": EduTypes.RECEIPT,
}
],
[
{
"content": {
"$1435641916114394fHBLK:matrix.org": {
ReceiptTypes.READ: {
"@user:jki.re": {
"ts": 1436451550453,
}
}
},
},
"room_id": "!jEsUZKDJdhlrceRyVU:example.org",
"type": EduTypes.RECEIPT,
}
],
)
def test_filters_out_receipt_event_with_only_private_receipt_and_ignores_rest(
self,
) -> None:
self._test_filters_private(
[
{
"content": {
"$14356419edgd14394fHBLK:matrix.org": {
ReceiptTypes.READ_PRIVATE: {
"@rikj:jki.re": {
"ts": 1436451550453,
},
}
},
},
"room_id": "!jEsUZKDJdhlrceRyVU:example.org",
"type": EduTypes.RECEIPT,
},
{
"content": {
"$1435641916114394fHBLK:matrix.org": {
ReceiptTypes.READ: {
"@user:jki.re": {
"ts": 1436451550453,
}
}
},
},
"room_id": "!jEsUZKDJdhlrceRyVU:example.org",
"type": EduTypes.RECEIPT,
},
],
[
{
"content": {
"$1435641916114394fHBLK:matrix.org": {
ReceiptTypes.READ: {
"@user:jki.re": {
"ts": 1436451550453,
}
}
}
},
"room_id": "!jEsUZKDJdhlrceRyVU:example.org",
"type": EduTypes.RECEIPT,
}
],
)
def test_handles_string_data(self) -> None:
"""
Tests that an invalid shape for read-receipts is handled.
Context: https://github.com/matrix-org/synapse/issues/10603
"""
self._test_filters_private(
[
{
"content": {
"$14356419edgd14394fHBLK:matrix.org": {
ReceiptTypes.READ: {
"@rikj:jki.re": "string",
}
},
},
"room_id": "!jEsUZKDJdhlrceRyVU:example.org",
"type": EduTypes.RECEIPT,
},
],
[
{
"content": {
"$14356419edgd14394fHBLK:matrix.org": {
ReceiptTypes.READ: {
"@rikj:jki.re": "string",
}
},
},
"room_id": "!jEsUZKDJdhlrceRyVU:example.org",
"type": EduTypes.RECEIPT,
},
],
)
def test_leaves_our_private_and_their_public(self) -> None:
self._test_filters_private(
[
{
"content": {
"$1dgdgrd5641916114394fHBLK:matrix.org": {
ReceiptTypes.READ_PRIVATE: {
"@me:server.org": {
"ts": 1436451550453,
},
},
ReceiptTypes.READ: {
"@rikj:jki.re": {
"ts": 1436451550453,
},
},
"a.receipt.type": {
"@rikj:jki.re": {
"ts": 1436451550453,
},
},
},
},
"room_id": "!jEsUZKDJdhlrceRyVU:example.org",
"type": EduTypes.RECEIPT,
}
],
[
{
"content": {
"$1dgdgrd5641916114394fHBLK:matrix.org": {
ReceiptTypes.READ_PRIVATE: {
"@me:server.org": {
"ts": 1436451550453,
},
},
ReceiptTypes.READ: {
"@rikj:jki.re": {
"ts": 1436451550453,
},
},
"a.receipt.type": {
"@rikj:jki.re": {
"ts": 1436451550453,
},
},
}
},
"room_id": "!jEsUZKDJdhlrceRyVU:example.org",
"type": EduTypes.RECEIPT,
}
],
)
def test_we_do_not_mutate(self) -> None:
"""Ensure the input values are not modified."""
events = [
{
"content": {
"$1435641916114394fHBLK:matrix.org": {
ReceiptTypes.READ_PRIVATE: {
"@rikj:jki.re": {
"ts": 1436451550453,
}
}
}
},
"room_id": "!jEsUZKDJdhlrceRyVU:example.org",
"type": EduTypes.RECEIPT,
}
]
original_events = deepcopy(events)
self._test_filters_private(events, [])
# Since the events are fed in from a cache they should not be modified.
self.assertEqual(events, original_events)
def _test_filters_private(
self, events: List[JsonDict], expected_output: List[JsonDict]
) -> None:
"""Tests that the _filter_out_private returns the expected output"""
filtered_events = self.event_source.filter_out_private_receipts(
events, "@me:server.org"
)
self.assertEqual(filtered_events, expected_output)