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

Creating new room with 3pid invite fails #5253

Closed
smoebody opened this issue May 24, 2019 · 14 comments · Fixed by #8001
Closed

Creating new room with 3pid invite fails #5253

smoebody opened this issue May 24, 2019 · 14 comments · Fixed by #8001
Assignees
Labels
z-bug (Deprecated Label) z-p2 (Deprecated Label)

Comments

@smoebody
Copy link

Description

When i try to add an existing user by clicking the plus-button in riot (https://riot.im/app/) and providing its email-address i get a quick lookup of that persons nickname. Then, when i submit i get

Failure to create room
Server may be unavailable, overloaded, or you hit a bug.

Steps to reproduce

  • create an account at https://riot.im/app/
  • click the plus-button to add a people
  • insert the email-address of an existing user
  • submit the form

Since the lookup works i also expect that the invite works. When i use the 3pid to invite the user it works flawlessly.

I can reproduce the behavior on my own instance, here are the logs - obfuscated

2019-05-24 15:59:50,501 - synapse.access.http.8008 - 302 - INFO - GET-10223- ::ffff:172.20.0.8 - 8008 - {@user1:example.com} Processed request: 0.044sec/0.001sec (0.018sec, 0.000sec) (0.005sec/0.008sec/3) 417B 200 "GET /_matrix/client/r0/sync?filter=0&timeout=30000&since=s216508_5155621_0_98013_1403_17_314_23461_2 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Riot/1.0.7 Chrome/69.0.3497.128 Electron/4.1.3 Safari/537.36" [0 dbevts]
2019-05-24 15:59:50,526 - synapse.http.client - 298 - INFO - POST-10211- Received response to GET https://matrix.example.com/_matrix/identity/api/v1/lookup?medium=email&address=user2%40example.com: 200
2019-05-24 15:59:50,531 - synapse.http.server - 85 - INFO - POST-10211- <SynapseRequest at 0x7f070c58fe48 method='POST' uri='/_matrix/client/r0/createRoom' clientproto='HTTP/1.1' site=8008> SynapseError: 401 - No signature from server matrix.example.com
2019-05-24 15:59:50,534 - synapse.access.http.8008 - 302 - INFO - POST-10211- ::ffff:172.20.0.8 - 8008 - {@user1:example.com} Processed request: 0.974sec/0.002sec (0.085sec, 0.009sec) (0.081sec/0.198sec/36) 97B 401 "POST /_matrix/client/r0/createRoom HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Riot/1.0.7 Chrome/69.0.3497.128 Electron/4.1.3 Safari/537.36" [6 dbevts]
2019-05-24 15:59:50,537 - synapse.access.http.8008 - 233 - INFO - OPTIONS-10224- ::ffff:172.20.0.8 - 8008 - Received request: OPTIONS /_matrix/client/r0/sync?filter=0&timeout=30000&since=s216509_5155621_0_98013_1403_17_314_23461_2
2019-05-24 15:59:50,539 - synapse.access.http.8008 - 302 - INFO - OPTIONS-10224- ::ffff:172.20.0.8 - 8008 - {None} Processed request: 0.001sec/0.001sec (0.002sec, 0.000sec) (0.000sec/0.000sec/0) 22B 200 "OPTIONS /_matrix/client/r0/sync?filter=0&timeout=30000&since=s216509_5155621_0_98013_1403_17_314_23461_2 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Riot/1.0.7 Chrome/69.0.3497.128 Electron/4.1.3 Safari/537.36" [0 dbevts]
2019-05-24 15:59:50,555 - synapse.access.http.8008 - 233 - INFO - GET-10225- ::ffff:172.20.0.8 - 8008 - Received request: GET /_matrix/client/r0/sync?filter=0&timeout=30000&since=s216509_5155621_0_98013_1403_17_314_23461_2
2019-05-24 15:59:50,558 - synapse.util.caches.response_cache - 151 - INFO - GET-10225- [sync]: no cached result for [(@user1:example.com, 30000, 's216509_5155621_0_98013_1403_17_314_23461_2', '0', False, 'SYEODRVLCR')], calculating new one
2019-05-24 15:59:50,703 - synapse.access.http.8008 - 233 - INFO - PUT-10226- ::ffff:172.20.0.8 - 8008 - Received request: PUT /_matrix/federation/v1/send/1558412703482

Version information

  • Homeserver:
    matrix.org as well as own instance matrix.metaccount.de
  • Version:
    The logs say 0.99.5.1

the curl-request the template suggests (without grep, because its not in the response) says :

{
    "unstable_features": {
        "m.lazy_load_members": true
    },
    "versions": [
        "r0.0.1",
        "r0.1.0",
        "r0.2.0",
        "r0.3.0",
        "r0.4.0"
    ]
}
  • Install method:

Docker-Container in a Compose-Stack

  • Platform:

official image from docker.io/matrixdotorg/synapse:latest

@richvdh
Copy link
Member

richvdh commented May 26, 2019

yeah. That's not ideal.

@richvdh richvdh added the p1 label May 26, 2019
@richvdh
Copy link
Member

richvdh commented May 26, 2019

This is what I see on my server:

2019-05-26 14:45:54,342 - synapse.access.http.8008 - 233 - INFO - POST-317340- 194.69.103.118 - 8008 - Received request: POST /_matrix/client/r0/createRoom
2019-05-26 14:45:54,353 - synapse.handlers.room - 666 - INFO - POST-317340- Sending m.room.create in new room
2019-05-26 14:45:54,404 - synapse.handlers.room - 689 - INFO - POST-317340- Sending m.room.member in new room
2019-05-26 14:45:54,487 - synapse.handlers.room - 666 - INFO - POST-317340- Sending m.room.power_levels in new room
2019-05-26 14:45:54,543 - synapse.handlers.room - 666 - INFO - POST-317340- Sending m.room.join_rules in new room
2019-05-26 14:45:54,599 - synapse.handlers.room - 666 - INFO - POST-317340- Sending m.room.history_visibility in new room
2019-05-26 14:45:54,649 - synapse.handlers.room - 666 - INFO - POST-317340- Sending m.room.guest_access in new room
2019-05-26 14:45:54,697 - synapse.http.client - 273 - INFO - POST-317340- Sending request GET https://vector.im/_matrix/identity/api/v1/lookup?address=REDACTED&medium=email
2019-05-26 14:45:54,878 - synapse.http.client - 298 - INFO - POST-317340- Received response to GET https://vector.im/_matrix/identity/api/v1/lookup?address=REDACTED&medium=email: 200
2019-05-26 14:45:54,879 - synapse.http.client - 273 - INFO - POST-317340- Sending request GET https://vector.im/_matrix/identity/api/v1/pubkey/ed25519:0
2019-05-26 14:45:54,912 - synapse.http.client - 298 - INFO - POST-317340- Received response to GET https://vector.im/_matrix/identity/api/v1/pubkey/ed25519:0: 200
2019-05-26 14:45:54,914 - synapse.http.server - 112 - ERROR - POST-317340- Failed handle request via 'RoomCreateRestServlet': <XForwardedForRequest at 0x7f6e028e1fd0 method='POST' uri='/_matrix/client/r0/createRoom' clientproto='HTTP/1.1' site=8008>
Capture point (most recent call last):
  File "/usr/lib/python3.5/runpy.py", line 184, in _run_module_as_main
    "__main__", mod_spec)
  File "/usr/lib/python3.5/runpy.py", line 85, in _run_code
    exec(code, run_globals)
  File "/opt/synapse/synapse/synapse/app/homeserver.py", line 663, in <module>
    main()
  File "/opt/synapse/synapse/synapse/app/homeserver.py", line 659, in main
    run(hs)
  File "/opt/synapse/synapse/synapse/app/homeserver.py", line 650, in run
    logger=logger,
  File "/opt/synapse/synapse/synapse/app/_base.py", line 146, in start_reactor
    run()
  File "/opt/synapse/synapse/synapse/app/_base.py", line 130, in run
    reactor.run()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/base.py", line 1267, in run
    self.mainLoop()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/base.py", line 1279, in mainLoop
    self.doIteration(t)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/epollreactor.py", line 235, in doPoll
    log.callWithLogger(selectable, _drdw, selectable, fd, event)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/python/log.py", line 103, in callWithLogger
    return callWithContext({"system": lp}, func, *args, **kw)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/python/log.py", line 86, in callWithContext
    return context.call({ILogContext: newCtx}, func, *args, **kw)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/python/context.py", line 122, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/python/context.py", line 85, in callWithContext
    return func(*args,**kw)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/posixbase.py", line 614, in _doReadOrWrite
    why = selectable.doRead()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/tcp.py", line 243, in doRead
    return self._dataReceived(data)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/tcp.py", line 249, in _dataReceived
    rval = self.protocol.dataReceived(data)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/endpoints.py", line 125, in dataReceived
    return self._wrappedProtocol.dataReceived(data)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/protocols/tls.py", line 330, in dataReceived
    self._flushReceiveBIO()
...
Traceback (most recent call last):
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/opt/synapse/synapse/synapse/http/client.py", line 494, in get_raw
    defer.returnValue(body)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1362, in returnValue
    raise _DefGen_Return(val)
twisted.internet.defer._DefGen_Return: b'{"public_key": "ta8IQ0u1sp44HVpxYi7dFOdS/bfwDjcy4xLFlfY5KOA"}'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/opt/synapse/synapse/synapse/http/client.py", line 416, in get_json
    defer.returnValue(json.loads(body))
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1362, in returnValue
    raise _DefGen_Return(val)
twisted.internet.defer._DefGen_Return: {'public_key': 'ta8IQ0u1sp44HVpxYi7dFOdS/bfwDjcy4xLFlfY5KOA'}

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/synapse/env3/lib/python3.5/site-packages/signedjson/sign.py", line 121, in verify_signed_json
    verify_key.verify(message, signature)
  File "/opt/synapse/env3/lib/python3.5/site-packages/nacl/signing.py", line 114, in verify
    return nacl.bindings.crypto_sign_open(smessage, self._key)
  File "/opt/synapse/env3/lib/python3.5/site-packages/nacl/bindings/crypto_sign.py", line 109, in crypto_sign_open
    raise exc.BadSignatureError("Signature was forged or corrupt")
nacl.exceptions.BadSignatureError: Signature was forged or corrupt

During handling of the above exception, another exception occurred:

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/synapse/synapse/synapse/http/server.py", line 81, in wrapped_request_handler
    yield h(self, request)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/opt/synapse/synapse/synapse/http/server.py", line 316, in _async_render
    callback_return = yield callback(request, **kwargs)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/opt/synapse/synapse/synapse/rest/client/v1/room.py", line 74, in on_POST
    requester, self.get_room_config(request)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/opt/synapse/synapse/synapse/handlers/room.py", line 626, in create_room
    txn_id=None,
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/opt/synapse/synapse/synapse/handlers/room_member.py", line 727, in do_3pid_invite
    id_server, medium, address
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/opt/synapse/synapse/synapse/handlers/room_member.py", line 778, in _lookup_3pid
    yield self._verify_any_signature(data, id_server)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/opt/synapse/synapse/synapse/handlers/room_member.py", line 800, in _verify_any_signature
    decode_verify_key_bytes(key_name, decode_base64(key_data["public_key"]))
  File "/opt/synapse/env3/lib/python3.5/site-packages/signedjson/sign.py", line 125, in verify_signed_json
    "Unable to verify signature for %s " % signature_name
signedjson.sign.SignatureVerifyException: Unable to verify signature for vector.im 

@babolivier
Copy link
Contributor

Possibly related to matrix-org/sydent#154

@richvdh
Copy link
Member

richvdh commented Sep 18, 2019

still a problem, for the record

@richvdh richvdh changed the title inviting existing user via email fails Creating new room with 3pid invite fails Sep 19, 2019
@richvdh
Copy link
Member

richvdh commented Sep 19, 2019

only seems to affect createRoom

@richvdh richvdh added z-bug (Deprecated Label) z-p2 (Deprecated Label) and removed p1 labels Feb 5, 2020
@richvdh
Copy link
Member

richvdh commented Jun 24, 2020

given that we can send 3pid invites reliably at other times, it feels like this ought to work.

Next steps: try to figure out what is different between the invite and the createRoom flows to see why the latter fails when the former succeeds.

@clokep
Copy link
Member

clokep commented Jul 21, 2020

Huh weirdly I cannot reproduce this. I wonder if my 3pid is too new (as is suggested in matrix-org/sydent#154?)

@anoadragon453
Copy link
Member

I am also unable to reproduce this on my own homeserver with a bunch of different email addresses, including some mentioned here. I had a quick skim through the code upon @richvdh's suggestion of trying to find discrepancies between the endpoints, and I found that they both just call RoomMemberHandler.do_3pid_invite, with /createRoom having the possibility of inviting more than one 3pid.

Looks like the exception occurs when the homeserver attempts to perform the deprecated v1 bind lookup on the identity server (if v2 hashed lookup failed). v1 still relies on signatures, and after receiving a lookup result, we call IdentityHandler._verify_any_signature on it:

async def _lookup_3pid_v1(
self, id_server: str, medium: str, address: str
) -> Optional[str]:
"""Looks up a 3pid in the passed identity server using v1 lookup.
Args:
id_server: The server name (including port, if required)
of the identity server to use.
medium: The type of the third party identifier (e.g. "email").
address: The third party identifier (e.g. "[email protected]").
Returns:
the matrix ID of the 3pid, or None if it is not recognized.
"""
try:
data = await self.blacklisting_http_client.get_json(
"%s%s/_matrix/identity/api/v1/lookup" % (id_server_scheme, id_server),
{"medium": medium, "address": address},
)
if "mxid" in data:
if "signatures" not in data:
raise AuthError(401, "No signatures on 3pid binding")
await self._verify_any_signature(data, id_server)
return data["mxid"]
except TimeoutError:
raise SynapseError(500, "Timed out contacting identity server")
except IOError as e:
logger.warning("Error from v1 identity server lookup: %s" % (e,))
return None

async def _verify_any_signature(self, data, server_hostname):
if server_hostname not in data["signatures"]:
raise AuthError(401, "No signature from server %s" % (server_hostname,))
for key_name, signature in data["signatures"][server_hostname].items():
try:
key_data = await self.blacklisting_http_client.get_json(
"%s%s/_matrix/identity/api/v1/pubkey/%s"
% (id_server_scheme, server_hostname, key_name)
)
except TimeoutError:
raise SynapseError(500, "Timed out contacting identity server")
if "public_key" not in key_data:
raise AuthError(
401, "No public key named %s from %s" % (key_name, server_hostname)
)
verify_signed_json(
data,
server_hostname,
decode_verify_key_bytes(
key_name, decode_base64(key_data["public_key"])
),
)
return

This then calls into python-signedjson, specifically the verify_signed_json method, which can raise a SignatureVerifyException: https://github.com/matrix-org/python-signedjson/blob/fea0bf62bb4eb8853757fb9577ade33878c47beb/signedjson/sign.py#L88-L99 which is what we saw happen in @richvdh's stacktrace up above.

I had a look in vector.im's sydent config, and the public key appears to have changed at some point some months ago. This would cause a discrepancy between the currently advertised public key, and the one used to sign old binds. I'm still checking internally whether this is the case - but if it is, I suppose the options we have are:

  1. Complete deprecation of the v1 lookup endpoint as 1. it's less secure than the hashed lookup method and 2. it doesn't rely on the signature verification stuff
  2. Resign all of the associations so they are signed with the new key
  3. Figure out a way for Sydent to advertise old, good keys, and have Synapse check for those.

I'm partial to either 1 or 2. 3 would take spec work and doesn't seem worth it compared to the others.

@anoadragon453 anoadragon453 self-assigned this Jul 28, 2020
@richvdh
Copy link
Member

richvdh commented Jul 29, 2020

I can believe this only happens on 3pids of a certain age. I'm still a bit confused about why it works when inviting a 3pid to an existing room, but fails when creating a new room

@richvdh
Copy link
Member

richvdh commented Jul 29, 2020

Updated stacktrace from createRoom:

2020-07-29 14:34:15,819 - synapse.http.client - 301 - INFO - POST-296301- Sending request GET https://vector.im/_matrix/identity/api/v1/lookup?medium=email&address=richardv%40matrix.org
2020-07-29 14:34:15,856 - synapse.replication.tcp.resource - 158 - INFO - replication_notifier-136864- Streaming: events -> 6704211
2020-07-29 14:34:15,907 - synapse.http.client - 340 - INFO - POST-296301- Received response to GET https://vector.im/_matrix/identity/api/v1/lookup?medium=email&address=richardv%40matrix.org: 200
2020-07-29 14:34:15,908 - synapse.http.client - 301 - INFO - POST-296301- Sending request GET https://vector.im/_matrix/identity/api/v1/pubkey/ed25519:0
2020-07-29 14:34:15,943 - synapse.http.client - 340 - INFO - POST-296301- Received response to GET https://vector.im/_matrix/identity/api/v1/pubkey/ed25519:0: 200
2020-07-29 14:34:15,945 - synapse.http.server - 83 - ERROR - POST-296301- Failed handle request via 'RoomCreateRestServlet': <XForwardedForRequest at 0x7fd68d9c9a58 method='POST' uri='/_matrix/client/r0/createRoom' clientproto='HTTP/1.1' site=8008>
Capture point (most recent call last):
  File "/usr/lib/python3.5/runpy.py", line 184, in _run_module_as_main
    "__main__", mod_spec)
  File "/usr/lib/python3.5/runpy.py", line 85, in _run_code
    exec(code, run_globals)
  File "/opt/synapse/synapse/synapse/app/homeserver.py", line 687, in <module>
    main()
  File "/opt/synapse/synapse/synapse/app/homeserver.py", line 683, in main
    run(hs)
  File "/opt/synapse/synapse/synapse/app/homeserver.py", line 674, in run
    logger=logger,
  File "/opt/synapse/synapse/synapse/app/_base.py", line 142, in start_reactor
    run()
  File "/opt/synapse/synapse/synapse/app/_base.py", line 117, in run
    run_command()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/base.py", line 1283, in run
    self.mainLoop()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/base.py", line 1295, in mainLoop
    self.doIteration(t)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/epollreactor.py", line 235, in doPoll
    log.callWithLogger(selectable, _drdw, selectable, fd, event)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/python/log.py", line 103, in callWithLogger
    return callWithContext({"system": lp}, func, *args, **kw)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/python/log.py", line 86, in callWithContext
    return context.call({ILogContext: newCtx}, func, *args, **kw)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/python/context.py", line 122, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/python/context.py", line 85, in callWithContext
    return func(*args,**kw)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/posixbase.py", line 614, in _doReadOrWrite
    why = selectable.doRead()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/tcp.py", line 243, in doRead
    return self._dataReceived(data)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/tcp.py", line 249, in _dataReceived
    rval = self.protocol.dataReceived(data)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/endpoints.py", line 132, in dataReceived
    return self._wrappedProtocol.dataReceived(data)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/protocols/tls.py", line 330, in dataReceived
    self._flushReceiveBIO()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/protocols/tls.py", line 295, in _flushReceiveBIO
    ProtocolWrapper.dataReceived(self, bytes)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/protocols/policies.py", line 120, in dataReceived
    self.wrappedProtocol.dataReceived(data)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/web/_newclient.py", line 1693, in dataReceived
    self._parser.dataReceived(bytes)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/web/_newclient.py", line 391, in dataReceived
    HTTPParser.dataReceived(self, data)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/protocols/basic.py", line 579, in dataReceived
    why = self.rawDataReceived(data)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/web/_newclient.py", line 304, in rawDataReceived
    self.bodyDecoder.dataReceived(data)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/web/http.py", line 1889, in dataReceived
    data = getattr(self, '_dataReceived_%s' % (self.state,))(data)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/web/http.py", line 1857, in _dataReceived_TRAILER
    self.finishCallback(data)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/web/_newclient.py", line 456, in _finished
    self.finisher(rest)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/web/_newclient.py", line 1050, in dispatcher
    return func(*args, **kwargs)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/web/_newclient.py", line 1647, in _finishResponse_WAITING
    self._disconnectParser(reason)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/web/_newclient.py", line 1673, in _disconnectParser
    parser.connectionLost(reason)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/web/_newclient.py", line 567, in connectionLost
    self.response._bodyDataFinished()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/web/_newclient.py", line 1050, in dispatcher
    return func(*args, **kwargs)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/web/_newclient.py", line 1306, in _bodyDataFinished_CONNECTED
    self._bodyProtocol.connectionLost(reason)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/web/client.py", line 2025, in connectionLost
    self.original.connectionLost(reason)
  File "/opt/synapse/env3/lib/python3.5/site-packages/treq/client.py", line 61, in connectionLost
    self.original.connectionLost(reason)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/web/client.py", line 2259, in connectionLost
    self.deferred.callback(b''.join(self.dataBuffer))
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 460, in callback
    self._startRunCallbacks(result)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 568, in _startRunCallbacks
    self._runCallbacks()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 654, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1475, in gotResult
    _inlineCallbacks(r, g, status)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1421, in _inlineCallbacks
    status.deferred.callback(getattr(e, "value", None))
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 460, in callback
    self._startRunCallbacks(result)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 568, in _startRunCallbacks
    self._runCallbacks()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 654, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1475, in gotResult
    _inlineCallbacks(r, g, status)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1421, in _inlineCallbacks
    status.deferred.callback(getattr(e, "value", None))
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 460, in callback
    self._startRunCallbacks(result)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 568, in _startRunCallbacks
    self._runCallbacks()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 654, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1475, in gotResult
    _inlineCallbacks(r, g, status)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/opt/synapse/synapse/synapse/http/server.py", line 168, in wrapped_async_request_handler
    await h(self, request)
Traceback (most recent call last):
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
StopIteration: b'{"public_key": "ta8IQ0u1sp44HVpxYi7dFOdS/bfwDjcy4xLFlfY5KOA"}'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
StopIteration: {'public_key': 'ta8IQ0u1sp44HVpxYi7dFOdS/bfwDjcy4xLFlfY5KOA'}

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/synapse/env3/lib/python3.5/site-packages/signedjson/sign.py", line 131, in verify_signed_json
    verify_key.verify(message, signature)
  File "/opt/synapse/env3/lib/python3.5/site-packages/nacl/signing.py", line 114, in verify
    return nacl.bindings.crypto_sign_open(smessage, self._key)
  File "/opt/synapse/env3/lib/python3.5/site-packages/nacl/bindings/crypto_sign.py", line 109, in crypto_sign_open
    raise exc.BadSignatureError("Signature was forged or corrupt")
nacl.exceptions.BadSignatureError: Signature was forged or corrupt

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/synapse/synapse/synapse/http/server.py", line 228, in _async_render_wrapper
    callback_return = await self._async_render(request)
  File "/opt/synapse/synapse/synapse/http/server.py", line 399, in _async_render
    callback_return = await raw_callback_return
  File "/opt/synapse/synapse/synapse/rest/client/v1/room.py", line 97, in on_POST
    requester, self.get_room_config(request)
  File "/opt/synapse/synapse/synapse/handlers/room.py", line 757, in create_room
    id_access_token=id_access_token,
  File "/opt/synapse/synapse/synapse/handlers/room_member.py", line 753, in do_3pid_invite
    id_server, medium, address, id_access_token
  File "/opt/synapse/synapse/synapse/handlers/identity.py", line 608, in lookup_3pid
    return await self._lookup_3pid_v1(id_server, medium, address)
  File "/opt/synapse/synapse/synapse/handlers/identity.py", line 633, in _lookup_3pid_v1
    await self._verify_any_signature(data, id_server)
  File "/opt/synapse/synapse/synapse/handlers/identity.py", line 773, in _verify_any_signature
    key_name, decode_base64(key_data["public_key"])
  File "/opt/synapse/env3/lib/python3.5/site-packages/signedjson/sign.py", line 135, in verify_signed_json
    signature_name, type(e), e,
signedjson.sign.SignatureVerifyException: Unable to verify signature for vector.im: <class 'nacl.exceptions.BadSignatureError'> Signature was forged or corrupt
2020-07-29 14:34:15,962 - synapse.access.http.8008 - 310 - INFO - POST-296301- 81.2.100.169 - 8008 - {@richvdh:sw1v.org} Processed request: 0.648sec/0.001sec (0.063sec, 0.007sec) (0.058sec/0.132sec/40) 55B 500 "POST /_matrix/client/r0/createRoom HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Element-Nightly/2020072701 Chrome/83.0.4103.119 Electron/9.0.5 Safari/537.36" [0 dbevts]

@richvdh
Copy link
Member

richvdh commented Jul 29, 2020

ah, so the difference is that riot isn't supplying an id_access_token for the createRoom call, which is why it is falling back to v1 lookup. Raised as element-hq/element-web#14814.

The upshot of that is that I don't think your option 1 (Complete deprecation of the v1 lookup endpoint) is going to fix this: we'll already use the v2 endpoint where the client provides the parameters we need: if we don't have the parameters we need for v2, we have the choice between a broken v1 api and an absent v1 api.

If the signing key on the sydent instance has really been rotated without using a new key ID, that is a matter of profound regret, but I guess the ship has sailed now. I'm not keen on re-signing them, especially if the signatures are redundant with v2.

Question: if we're happy to use the v2 api without any signatures, why do we insist on a valid signature from the v1 api? what if we skip the signature validation?

@richvdh
Copy link
Member

richvdh commented Jul 29, 2020

If the signing key on the sydent instance has really been rotated without using a new key ID

See also matrix-org/sydent#154.

@anoadragon453
Copy link
Member

Question: if we're happy to use the v2 api without any signatures, why do we insist on a valid signature from the v1 api? what if we skip the signature validation?

I've talked to @dbkr about this ages ago and remember the conclusion that it was an overly paranoid check, which is why it was eliminated from the v2 API. I wouldn't be adverse to removing the check in Synapse, and that is a very simple solution to this whole mess.

The identity service spec could use some updates after this.

@richvdh
Copy link
Member

richvdh commented Jul 30, 2020

I wouldn't be adverse to removing the check in Synapse, and that is a very simple solution to this whole mess.

cool. could you do that then please?

anoadragon453 added a commit that referenced this issue Aug 3, 2020
We've [decided](#5253 (comment)) to remove the signature check for v1 lookups.

The signature check has been removed in v2 lookups. v1 lookups are currently deprecated. As mentioned in the above linked issue, this verification was causing deployments for the vector.im and matrix.org IS deployments, and this change is the simplest solution, without being unjustified.

Implementations are encouraged to use the v2 lookup API as it has [increased privacy benefits](matrix-org/matrix-spec-proposals#2134).
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
z-bug (Deprecated Label) z-p2 (Deprecated Label)
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants