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

Synapse is sending non-local events over federation #1753

Closed
ara4n opened this issue Jan 3, 2017 · 10 comments
Closed

Synapse is sending non-local events over federation #1753

ara4n opened this issue Jan 3, 2017 · 10 comments

Comments

@ara4n
Copy link
Member

ara4n commented Jan 3, 2017

I'm seeing events being sent over federation which don't belong to the origin homeserver. For instance, arasphere just received a PDU (from a 0.18.5 server) with:

{
  "origin": "z.z6c.de",
  "pdu_failures": [],
  "pdus": [
    {
      "origin": "matrix.org",
      "signatures": {
        "matrix.org": {
          "ed25519:auto": "WuztFoe9VvIN/yWbDaNv0J0k3I+N8h7jMHwKxUfaNDW95Dwir2IpSrfvPfZtTsHoxZNSUedBZ1ROWfey1UhsCg"
        }
      },
      "origin_server_ts": 1483453013455,
      "sender": "@fabrixxm:matrix.org",
      "event_id": "$1483453013893727UICoI:matrix.org",
      "prev_events": [
        [
          "$1483452773892201kRpFJ:matrix.org",
          {
            "sha256": "75MioxOAbqrzo6QGZJfZ7AlZiyYvydnpJSGcNpndR1w"
          }
        ]
      ],
      "membership": "leave",
      "state_key": "@fabrixxm:matrix.org",
      "unsigned": {
        "prev_content": {
          "membership": "join",
          "avatar_url": "mxc://matrix.org/LaCoUzvXdJOlEZyeEQGdVlxq",
          "displayname": "Fabrix Xm"
        },
        "prev_sender": "@fabrixxm:matrix.org",
        "replaces_state": "$1452354098111668afGlF:matrix.org",
        "age_ts": 1483453013455
      },
      "content": {
        "membership": "leave"
      },
      "depth": 221281,
      "prev_state": [],
      "room_id": "!cURbafjkfsMDVwdRDQ:matrix.org",
      "auth_events": [
        [
          "$1416420717069yeQaw:matrix.org",
          {
            "sha256": "SQbXz8UcBT39JJs/J9hqWb8INde/p4pkr9AG6gk7EtY"
          }
        ],
        [
          "$1452354098111668afGlF:matrix.org",
          {
            "sha256": "g2KHft6fDkf/NdXOJVYXUQPEq+2LGd9yHYXfrtFtnzY"
          }
        ],
        [
          "$1481884141991RFQcS:sw1v.org",
          {
            "sha256": "nPHidirGOvlr/nGaUPNWJ9pQ1N9+tzGk9/l95xhYerg"
          }
        ]
      ],
      "hashes": {
        "sha256": "PzNhdd1BA6ffJOfb7Md6pRygHEThgDhi87JL3zyXWf4"
      },
      "type": "m.room.member"
    }
  ],
  "origin_server_ts": 1483453015399
}

Why on earth is z.z6c.de sending events originating from matrix.org?
I've seen something looking like this a few times whilst debugging #1733 and #1738, but this is the first time i've caught it in the act with debug-level logging.

@ara4n
Copy link
Member Author

ara4n commented Jan 5, 2017

I'm suddenly worried that this may be causing a federation storm, where rather than each event being sent only by the origin server, it's also sent simultaneously by other servers too, resulting in N-times more traffic flying around...

@ara4n
Copy link
Member Author

ara4n commented Jan 5, 2017

This might explain @Tokodomo's syn flood warnings on federation traffic, if we're receiving the same event in quick succession from a random set of homeservers. It might also explain why we're hitting deadlocks more often?

@ara4n
Copy link
Member Author

ara4n commented Jan 5, 2017

This is indeed happening. I ran arasphere in debug mode this afternoon for a few hours, and stripped all the event_ids out of the fed txns it received. Many events arrive from different homeservers, duplicated 40-50x over. For instance, event $14835496121490460FllQW:matrix.org was received in the following PDUs:

2017-01-04 17:07:00,584 - synapse.federation.transport.server - 244 - INFO - PUT-20294- Received txn 1483296111106 from matrix.org. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:01,107 - synapse.federation.transport.server - 244 - INFO - PUT-20295- Received txn 1483352879376 from z.z6c.de. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:01,161 - synapse.federation.transport.server - 244 - INFO - PUT-20296- Received txn 1483523257891 from h3ndr1k.de. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:01,416 - synapse.federation.transport.server - 244 - INFO - PUT-20297- Received txn 1483420849920 from raim.ist. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:01,429 - synapse.federation.transport.server - 244 - INFO - PUT-20298- Received txn 1483532904007 from matrix.trancendances.fr. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:01,477 - synapse.federation.transport.server - 244 - INFO - PUT-20299- Received txn 1483417084608 from edutel.nl. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:01,532 - synapse.federation.transport.server - 244 - INFO - PUT-20300- Received txn 1483190077262 from cryptmessage.org. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:01,554 - synapse.federation.transport.server - 244 - INFO - PUT-20301- Received txn 1483178507620 from anemone.me. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:01,568 - synapse.federation.transport.server - 244 - INFO - PUT-20302- Received txn 1483081969520 from matrix.initq.net. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:01,683 - synapse.federation.transport.server - 244 - INFO - PUT-20303- Received txn 1483538960381 from krtdex.com. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:01,761 - synapse.federation.transport.server - 244 - INFO - PUT-20304- Received txn 1483540614413 from onedefence.com. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:01,868 - synapse.federation.transport.server - 244 - INFO - PUT-20305- Received txn 1483538255711 from d120.de. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:02,133 - synapse.federation.transport.server - 244 - INFO - PUT-20306- Received txn 1482775715675 from matrix.6502.me. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:02,233 - synapse.federation.transport.server - 244 - INFO - PUT-20307- Received txn 1482527806549 from dusky.horse. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:02,368 - synapse.federation.transport.server - 244 - INFO - PUT-20309- Received txn 1483400810743 from atauno.com. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:02,520 - synapse.federation.transport.server - 244 - INFO - PUT-20310- Received txn 1483400499520 from hveem.no. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:02,624 - synapse.federation.transport.server - 244 - INFO - PUT-20311- Received txn 1483281149753 from sjemm.net. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:02,945 - synapse.federation.transport.server - 244 - INFO - PUT-20312- Received txn 1483156264688 from matrix.feder8.ru. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:03,086 - synapse.federation.transport.server - 244 - INFO - PUT-20313- Received txn 1483546610287 from disroot.org. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:03,332 - synapse.federation.transport.server - 244 - INFO - PUT-20314- Received txn 1483537176099 from nsa.wtf. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:03,347 - synapse.federation.transport.server - 244 - INFO - PUT-20315- Received txn 1483131143648 from terracrypt.net. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:03,368 - synapse.federation.transport.server - 244 - INFO - PUT-20316- Received txn 1483494039354 from intelfx.name. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:04,138 - synapse.federation.transport.server - 244 - INFO - PUT-20318- Received txn 1483543878435 from catalk.xyz. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:05,220 - synapse.federation.transport.server - 244 - INFO - PUT-20319- Received txn 1483139361885 from maxwellkepler.uk. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:05,233 - synapse.federation.transport.server - 244 - INFO - PUT-20320- Received txn 1483317868265 from karp.id.au. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:05,240 - synapse.federation.transport.server - 244 - INFO - PUT-20321- Received txn 1483544424265 from matrixim.cc. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:06,247 - synapse.federation.transport.server - 244 - INFO - PUT-20322- Received txn 1483512302822 from chat.weho.st. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:06,307 - synapse.federation.transport.server - 244 - INFO - PUT-20323- Received txn 1483124908212 from stvn.cc. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:06,638 - synapse.federation.transport.server - 244 - INFO - PUT-20325- Received txn 1483215466672 from matrix.rkm.id.au. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:07,964 - synapse.federation.transport.server - 244 - INFO - PUT-20327- Received txn 1483446135534 from matrix.clerisy.info. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:08,285 - synapse.federation.transport.server - 244 - INFO - PUT-20328- Received txn 1483549239159 from matrix.xsteadfastx.org. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:08,713 - synapse.federation.transport.server - 244 - INFO - PUT-20329- Received txn 1483143022801 from kvlt.ee. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:08,758 - synapse.federation.transport.server - 244 - INFO - PUT-20330- Received txn 1483546656337 from kyriasis.com. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:09,322 - synapse.federation.transport.server - 244 - INFO - PUT-20332- Received txn 1483543899057 from tapenet.org. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:10,751 - synapse.federation.transport.server - 244 - INFO - PUT-20334- Received txn 1483544824627 from ghostcorp.net. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:10,846 - synapse.federation.transport.server - 244 - INFO - PUT-20336- Received txn 1483474795743 from thewordnerd.info. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:11,069 - synapse.federation.transport.server - 244 - INFO - PUT-20337- Received txn 1483129457927 from waffle.tech. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:11,617 - synapse.federation.transport.server - 244 - INFO - PUT-20338- Received txn 1483528010793 from matrix.mynock.rezosup.org. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:13,345 - synapse.federation.transport.server - 244 - INFO - PUT-20339- Received txn 1483126879747 from matrix.recursiv.com. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:16,538 - synapse.federation.transport.server - 244 - INFO - PUT-20343- Received txn 1483534217626 from 0db.nl. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:21,628 - synapse.federation.transport.server - 244 - INFO - PUT-20348- Received txn 1483537555967 from productionservers.net. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:22,231 - synapse.federation.transport.server - 244 - INFO - PUT-20350- Received txn 1483545460341 from half-shot.uk. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:24,651 - synapse.federation.transport.server - 244 - INFO - PUT-20356- Received txn 1483303469645 from saumon.ninja. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:25,118 - synapse.federation.transport.server - 244 - INFO - PUT-20358- Received txn 1483398037849 from dewitte.id.au. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:27,758 - synapse.federation.transport.server - 244 - INFO - PUT-20362- Received txn 1483352157468 from stratum0.org. (PDUs: 1, EDUs: 1, failures: 0)
2017-01-04 17:07:29,118 - synapse.federation.transport.server - 244 - INFO - PUT-20363- Received txn 1483302756018 from t2l.io. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:29,151 - synapse.federation.transport.server - 244 - INFO - PUT-20364- Received txn 1483401556256 from sijmenschoon.nl. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:35,928 - synapse.federation.transport.server - 244 - INFO - PUT-20367- Received txn 1483441299376 from binets.fr. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:40,018 - synapse.federation.transport.server - 244 - INFO - PUT-20371- Received txn 1483137220700 from lynxie.net. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:41,574 - synapse.federation.transport.server - 244 - INFO - PUT-20372- Received txn 1483537201197 from 57north.org.uk. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:44,424 - synapse.federation.transport.server - 244 - INFO - PUT-20378- Received txn 1483544345540 from safaradeg.net. (PDUs: 1, EDUs: 0, failures: 0)
2017-01-04 17:07:49,616 - synapse.federation.transport.server - 244 - INFO - PUT-20383- Received txn 1483538144028 from jki.re. (PDUs: 1, EDUs: 0, failures: 0)

@ara4n
Copy link
Member Author

ara4n commented Jan 5, 2017

It may be coincidence, but every single one of those duplicates came from 0.18.5 (or 0.18.6)

@NegativeMjark
Copy link
Contributor

Looks like https://github.com/matrix-org/synapse/blob/v0.18.5/synapse/federation/transaction_queue.py#L146-L170 doesn't have a check to make sure we only send events from this server.

@NegativeMjark
Copy link
Contributor

NegativeMjark commented Jan 5, 2017

This was probably introduced when we split out the federation sender to a worker and the code was rewritten to pull events from the database. #1635

@NegativeMjark
Copy link
Contributor

It looks like synapse pre-0.18.5 used to send messages on behalf of other servers under certain circumstances. https://github.com/matrix-org/synapse/pull/1635/files#diff-3f6de39b112e0c501c3c2925a571b908L850

I guess that was why the check to ensure the event came from this server was omitted from #1635.

@NegativeMjark
Copy link
Contributor

#1764 might fix this.

@ara4n
Copy link
Member Author

ara4n commented Jan 7, 2017

It didn't fix it. but hopefully b2850e6 does.

@ara4n
Copy link
Member Author

ara4n commented Jan 7, 2017

this is tested in the wild and seen to be working at last.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

3 participants