Suspected flake: Inbound federation redacts events from erased users

[DMRobertson]

E.g. https://github.com/matrix-org/synapse/runs/5405867110?check_suite_focus=true

I was able to reproduce this locally with

docker run --rm -v /home/dmr/workspace/synapse-plain:/src:ro -v /home/dmr/workspace/sytest/:/sytest -v /tmp/logs:/logs -e POSTGRES=1 -e WORKERS=1 -e MULTI_POSTGRES=1 -e SYNAPSE_TEST_LOG_LEVEL=DEBUG matrixdotorg/sytest-synapse:testing --torture-replication 50 -s tests/50federation/32room-getevent.pl

[DMRobertson]

Couldn't reproduce on Synapse v1.53. Bisecting shows that this was introduced by matrix-org/synapse@dc9fe61 (matrix-org/synapse#11999). So maybe this is a Synapse problem rather than a Sytest problem.

[DMRobertson]

Sytest's output: results.txt

When sytest queries the homeserver under test, it first gets an unredacted copy of the event. It tries again with the same result. Thereafter, the HS under test returns 403 forbidden ("host not in room").

Do we need to have a second user on the HS under test join the room?

[richvdh]

the test in question is https://github.com/matrix-org/sytest/blob/develop/tests/50federation/32room-getevent.pl#L44

... and the test output is:

not ok 2 Inbound federation redacts events from erased users
# Started: 2022-03-03 13:27:17.185
# Ended: 2022-03-03 13:27:22.517
# HTTP Request failed ( 403 Forbidden https://localhost:8840/_matrix/federation/v1/event/$foEHR4T7fH34kyTEgxGj9C3upXcx2JBAqKV9MK6VhxM ) from GET https://localhost:8840/_matrix/federation/v1/event/$foEHR4T7fH34kyTEgxGj9C3upXcx2JBAqKV9MK6VhxM?...
# {"errcode":"M_FORBIDDEN","error":"Host not in room."}
# 0.029239: Registered new user @anon-20220303_132710-2:localhost:8840
# 0.347992: Joined room 1: !PAmKZcEUJthxwemPWZ:localhost:8840
# 0.372219: Sent 'm.room.message' event in !PAmKZcEUJthxwemPWZ:localhost:8840: $foEHR4T7fH34kyTEgxGj9C3upXcx2JBAqKV9MK6VhxM
# 0.381499: Fetched event before erasure
# {
#   origin => "localhost:8840",
#   origin_server_ts => JSON::number(1646314037565),
#   pdus => [
#     {
#       auth_events      => [
#                             "\$Lg2Gx4ivJnpjpkFVmoYjrQlzfy9a72vmi3MaTOQ6rks",
#                             "\$kRbELNWCq3m7qP8HIuMfs3Gr4kY58beug8zW_8jiOi8",
#                             "\$BYiHM2tFNNFfHXTHL5vDNOCtnkvK4km9TzA13L0Jl4w",
#                           ],
#       content          => { body => "body1", msgtype => "m.text" },
#       depth            => JSON::number(7),
#       hashes           => { sha256 => "aZge0CY9YSHyZI19myfgb8xyecuj3VXmn22fZpsdCV8" },
#       origin           => "localhost:8840",
#       origin_server_ts => JSON::number(1646314037540),
#       prev_events      => ["\$s8yYJurgeDxKIS3YVOEij81i7sLzWpKxh-c1xAHWjVM"],
#       prev_state       => [],
#       room_id          => "!PAmKZcEUJthxwemPWZ:localhost:8840",
#       sender           => "\@anon-20220303_132710-2:localhost:8840",
#       signatures       => {
#                             "localhost:8840" => {
#                               "ed25519:a_zpWQ" => "bHCzmTssymxJYXdZPj107iviaYEIYAny0G8UCbca6Kh0WcfYEFA0IUcaMJ8fGQh+hz2EfXZCdn2FOaE9GerEBA",
#                             },
#                           },
#       type             => "m.room.message",
#       unsigned         => { age => JSON::number(25) },
#     },
#   ],
# }
# 0.464956: Fetched event after erasure
# {
#   origin => "localhost:8840",
#   origin_server_ts => JSON::number(1646314037648),
#   pdus => [
#     {
#       auth_events      => [
#                             "\$Lg2Gx4ivJnpjpkFVmoYjrQlzfy9a72vmi3MaTOQ6rks",
#                             "\$kRbELNWCq3m7qP8HIuMfs3Gr4kY58beug8zW_8jiOi8",
#                             "\$BYiHM2tFNNFfHXTHL5vDNOCtnkvK4km9TzA13L0Jl4w",
#                           ],
#       content          => { body => "body1", msgtype => "m.text" },
#       depth            => JSON::number(7),
#       hashes           => { sha256 => "aZge0CY9YSHyZI19myfgb8xyecuj3VXmn22fZpsdCV8" },
#       origin           => "localhost:8840",
#       origin_server_ts => JSON::number(1646314037540),
#       prev_events      => ["\$s8yYJurgeDxKIS3YVOEij81i7sLzWpKxh-c1xAHWjVM"],
#       prev_state       => [],
#       room_id          => "!PAmKZcEUJthxwemPWZ:localhost:8840",
#       sender           => "\@anon-20220303_132710-2:localhost:8840",
#       signatures       => {
#                             "localhost:8840" => {
#                               "ed25519:a_zpWQ" => "bHCzmTssymxJYXdZPj107iviaYEIYAny0G8UCbca6Kh0WcfYEFA0IUcaMJ8fGQh+hz2EfXZCdn2FOaE9GerEBA",
#                             },
#                           },
#       type             => "m.room.message",
#       unsigned         => { age => JSON::number(108) },
#     },
#   ],
# }
# 0.465445: Iteration 1++: not ready yet: Event was not redacted at tests/50federation/32room-getevent.pl line 104.
# 0.620652: Fetched event after erasure
# {
#   origin => "localhost:8840",
#   origin_server_ts => JSON::number(1646314037804),
#   pdus => [
#     {
#       auth_events      => [
#                             "\$Lg2Gx4ivJnpjpkFVmoYjrQlzfy9a72vmi3MaTOQ6rks",
#                             "\$kRbELNWCq3m7qP8HIuMfs3Gr4kY58beug8zW_8jiOi8",
#                             "\$BYiHM2tFNNFfHXTHL5vDNOCtnkvK4km9TzA13L0Jl4w",
#                           ],
#       content          => { body => "body1", msgtype => "m.text" },
#       depth            => JSON::number(7),
#       hashes           => { sha256 => "aZge0CY9YSHyZI19myfgb8xyecuj3VXmn22fZpsdCV8" },
#       origin           => "localhost:8840",
#       origin_server_ts => JSON::number(1646314037540),
#       prev_events      => ["\$s8yYJurgeDxKIS3YVOEij81i7sLzWpKxh-c1xAHWjVM"],
#       prev_state       => [],
#       room_id          => "!PAmKZcEUJthxwemPWZ:localhost:8840",
#       sender           => "\@anon-20220303_132710-2:localhost:8840",
#       signatures       => {
#                             "localhost:8840" => {
#                               "ed25519:a_zpWQ" => "bHCzmTssymxJYXdZPj107iviaYEIYAny0G8UCbca6Kh0WcfYEFA0IUcaMJ8fGQh+hz2EfXZCdn2FOaE9GerEBA",
#                             },
#                           },
#       type             => "m.room.message",
#       unsigned         => { age => JSON::number(264) },
#     },
#   ],
# }
# 0.621078: Iteration 2++: not ready yet: Event was not redacted at tests/50federation/32room-getevent.pl line 104.
# 0.852417: Iteration 3++: not ready yet: HTTP Request failed ( 403 Forbidden https://localhost:8840/_matrix/federation/v1/event/$foEHR4T7fH34kyTEgxGj9C3upXcx2JBAqKV9MK6VhxM ) from GET https://localhost:8840/_matrix/federation/v1/event/$foEHR4T7fH34kyTEgxGj9C3upXcx2JBAqKV9MK6VhxM?...
{"errcode":"M_FORBIDDEN","error":"Host not in room."}
# 1.195277: Iteration 4++: not ready yet: HTTP Request failed ( 403 Forbidden https://localhost:8840/_matrix/federation/v1/event/$foEHR4T7fH34kyTEgxGj9C3upXcx2JBAqKV9MK6VhxM ) from GET https://localhost:8840/_matrix/federation/v1/event/$foEHR4T7fH34kyTEgxGj9C3upXcx2JBAqKV9MK6VhxM?...
{"errcode":"M_FORBIDDEN","error":"Host not in room."}
# 1.706554: Iteration 5++: not ready yet: HTTP Request failed ( 403 Forbidden https://localhost:8840/_matrix/federation/v1/event/$foEHR4T7fH34kyTEgxGj9C3upXcx2JBAqKV9MK6VhxM ) from GET https://localhost:8840/_matrix/federation/v1/event/$foEHR4T7fH34kyTEgxGj9C3upXcx2JBAqKV9MK6VhxM?...
{"errcode":"M_FORBIDDEN","error":"Host not in room."}
# 2.471461: Iteration 6++: not ready yet: HTTP Request failed ( 403 Forbidden https://localhost:8840/_matrix/federation/v1/event/$foEHR4T7fH34kyTEgxGj9C3upXcx2JBAqKV9MK6VhxM ) from GET https://localhost:8840/_matrix/federation/v1/event/$foEHR4T7fH34kyTEgxGj9C3upXcx2JBAqKV9MK6VhxM?...
{"errcode":"M_FORBIDDEN","error":"Host not in room."}
# 3.615559: Iteration 7++: not ready yet: HTTP Request failed ( 403 Forbidden https://localhost:8840/_matrix/federation/v1/event/$foEHR4T7fH34kyTEgxGj9C3upXcx2JBAqKV9MK6VhxM ) from GET https://localhost:8840/_matrix/federation/v1/event/$foEHR4T7fH34kyTEgxGj9C3upXcx2JBAqKV9MK6VhxM?...
{"errcode":"M_FORBIDDEN","error":"Host not in room."}
# 5.331095: Iteration 8++: not ready yet: HTTP Request failed ( 403 Forbidden https://localhost:8840/_matrix/federation/v1/event/$foEHR4T7fH34kyTEgxGj9C3upXcx2JBAqKV9MK6VhxM ) from GET https://localhost:8840/_matrix/federation/v1/event/$foEHR4T7fH34kyTEgxGj9C3upXcx2JBAqKV9MK6VhxM?...
{"errcode":"M_FORBIDDEN","error":"Host not in room."}

[richvdh]

Do we need to have a second user on the HS under test join the room?

yes, I think so!