dendrite Irretrievable event causing backfill failure

Irretrievable event causing backfill failure

Open Pestdoktor opened this issue 4 years ago • 15 comments

Background information

Dendrite version or git SHA: v0.20.0rc2
Monolith or Polylith?: monolith
SQLite3 or Postgres?: postgres
Running in Docker?: yes

Steps to reproduce

join !mjbDjyNsRXndKLkHIe:matrix.org
perform initial sync
GET /_matrix/client/r0/rooms/!mjbDjyNsRXndKLkHIe%3Amatrix.org/messages?dir=b&from=<token from sync>
returns {"errcode":"M_UNKNOWN","error":"Internal Server Error"}

Logs

time="2020-10-19T17:09:05.546607375Z" level=info msg="Fetched 0 events locally" func="github.com/matrix-org/dendrite/syncapi/routing.(*messagesReq).retrieveEvents" file="github.com/matrix-org/dendrite@/syncapi/routing/messages.go:212" end="{{ []}}" req.id=9bhlHdScHKhw req.method=GET req.path="/_matrix/client/r0/rooms/!mjbDjyNsRXndKLkHIe:matrix.org/messages" start="{{ []}}" user_id="@pestdoktor:fentker.eu"
time="2020-10-19T17:09:05.557817343Z" level=info msg="ServersAtEvent history visibility not shared: world_readable" func=github.com/matrix-org/dendrite/roomserver/internal/perform.joinEventsFromHistoryVisibility file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:530"
time="2020-10-19T17:09:05.557858626Z" level=info msg="ServersAtEvent including 0 current events from history visibility" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).ServersAtEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:434"
time="2020-10-19T17:09:05.956193305Z" level=info msg="Received transaction \"1602604817201\" from \"nct08.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=BTUFN2dOitOi req.method=PUT req.path=/_matrix/federation/v1/send/1602604817201
time="2020-10-19T17:09:06.004682959Z" level=info msg="Received transaction \"1602761881584\" from \"maralorn.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=OAJgbazvmHCn req.method=PUT req.path=/_matrix/federation/v1/send/1602761881584
time="2020-10-19T17:09:07.295568476Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$8Xeu4i5C5Hd9dFW-RaKcDIdM6YBKNUTMjepMHuTMLaU"
time="2020-10-19T17:09:07.395364946Z" level=info msg="Received transaction \"1602776611040\" from \"maunium.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=U6ToAjsHmj9n req.method=PUT req.path=/_matrix/federation/v1/send/1602776611040
time="2020-10-19T17:09:08.476914103Z" level=info msg="Received transaction \"1603045743198\" from \"elsmussols.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=kaLD7OX2cYNr req.method=PUT req.path=/_matrix/federation/v1/send/1603045743198
time="2020-10-19T17:09:08.679493496Z" level=info msg="Received transaction \"1602957381103\" from \"tincan.community\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=klfwRt1nphp2 req.method=PUT req.path=/_matrix/federation/v1/send/1602957381103
time="2020-10-19T17:09:08.855143915Z" level=info msg="Received transaction \"1602957381596\" from \"tincan.community\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=GgMw0wdwSt2m req.method=PUT req.path=/_matrix/federation/v1/send/1602957381596
time="2020-10-19T17:09:09.507646066Z" level=info msg="Received transaction \"1603125365212\" from \"binux.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=Urzi9GPh4skq req.method=PUT req.path=/_matrix/federation/v1/send/1603125365212
time="2020-10-19T17:09:09.641088921Z" level=info msg="Received transaction \"1603125366743\" from \"binux.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=HITgikphlHeK req.method=PUT req.path=/_matrix/federation/v1/send/1603125366743
time="2020-10-19T17:09:09.673752046Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$iv0p49AdYzDtJoUXuit8HU9Cr1v27iDd5Wl3SCnn7cw"
time="2020-10-19T17:09:10.740369766Z" level=info msg="Received transaction \"1602881160695\" from \"kif.rocks\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=tf37qxjGd4wS req.method=PUT req.path=/_matrix/federation/v1/send/1602881160695
time="2020-10-19T17:09:11.567585230Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$tsuoZ2VhIVCYANkiY2cEkudEVG5NkNzd5h_H8JpFAa8"
time="2020-10-19T17:09:11.869531401Z" level=info msg="Received transaction \"1602881162839\" from \"kif.rocks\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=BdmMp5n4R3br req.method=PUT req.path=/_matrix/federation/v1/send/1602881162839
time="2020-10-19T17:09:12.235681898Z" level=info msg="Received transaction \"1602818673840\" from \"sunbutt.faith\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=iNcpp2fJQAPE req.method=PUT req.path=/_matrix/federation/v1/send/1602818673840
time="2020-10-19T17:09:12.284942772Z" level=info msg="Received transaction \"1602818674991\" from \"sunbutt.faith\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=k7lJwyWY2GBa req.method=PUT req.path=/_matrix/federation/v1/send/1602818674991
time="2020-10-19T17:09:12.903727630Z" level=info msg="Received transaction \"1597683032658\" from \"mustelo.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=NsbbWZ6CmYe9 req.method=PUT req.path=/_matrix/federation/v1/send/1597683032658
time="2020-10-19T17:09:13.258060529Z" level=info msg="Received transaction \"1603045744280\" from \"elsmussols.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=U2Na96SVLenC req.method=PUT req.path=/_matrix/federation/v1/send/1603045744280
time="2020-10-19T17:09:13.376430579Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$-_oMnpQXYmykRaItc5IZGOF24z7FqrklEyVqDADjK-Y"
time="2020-10-19T17:09:15.043705603Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$RxgEldV22AL21F-y67z41RRCVEy1RIWAbVq9sPeduW8"
time="2020-10-19T17:09:15.549669459Z" level=info msg="Received transaction \"1603124348401\" from \"polonkai.eu\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=WMRIIzVjlZJr req.method=PUT req.path=/_matrix/federation/v1/send/1603124348401
time="2020-10-19T17:09:16.157352073Z" level=info msg="Received transaction \"1602849979637\" from \"matrix.org\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=DzN7ZuL42w3D req.method=PUT req.path=/_matrix/federation/v1/send/1602849979637
time="2020-10-19T17:09:16.158252389Z" level=info msg=DeviceListUpdater.Update func="github.com/matrix-org/dendrite/keyserver/internal.(*DeviceListUpdater).update" file="github.com/matrix-org/dendrite@/keyserver/internal/device_list_update.go:201" context=missing deleted=false device_id=INRASCKFZV display_name="Element Desktop (Linux)" prev_ids="[390936958]" prev_ids_exist=false stream_id=390962930 user_id="@debian-user:matrix.org"
time="2020-10-19T17:09:16.337195626Z" level=info msg="Received transaction \"1602844507339\" from \"im.kabi.tk\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=HsOlgbFBWZ6w req.method=PUT req.path=/_matrix/federation/v1/send/1602844507339
time="2020-10-19T17:09:16.444923768Z" level=info msg="Produced to key change topic 'DendriteOutputKeyChangeEvent'" func="github.com/matrix-org/dendrite/keyserver/producers.(*KeyChange).ProduceKeyChanges" file="github.com/matrix-org/dendrite@/keyserver/producers/keychange.go:72" num_key_changes=1 user_id="@debian-user:matrix.org"
time="2020-10-19T17:09:16.564008264Z" level=info msg="Received transaction \"1602844508672\" from \"im.kabi.tk\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=ZZgwhCdl9nNZ req.method=PUT req.path=/_matrix/federation/v1/send/1602844508672
time="2020-10-19T17:09:16.586148472Z" level=info msg="Received transaction \"1602838078198\" from \"planetdecred.org\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=j8sG1TMTTr5g req.method=PUT req.path=/_matrix/federation/v1/send/1602838078198
time="2020-10-19T17:09:16.975320035Z" level=info msg="Received transaction \"1602849979713\" from \"matrix.org\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=RQCJWl0VLsVD req.method=PUT req.path=/_matrix/federation/v1/send/1602849979713
time="2020-10-19T17:09:16.975596650Z" level=info msg=DeviceListUpdater.Update func="github.com/matrix-org/dendrite/keyserver/internal.(*DeviceListUpdater).update" file="github.com/matrix-org/dendrite@/keyserver/internal/device_list_update.go:201" context=missing deleted=false device_id=INRASCKFZV display_name="Element Desktop (Linux)" prev_ids="[390962930]" prev_ids_exist=false stream_id=390963439 user_id="@debian-user:matrix.org"
time="2020-10-19T17:09:17.237501770Z" level=info msg="Received transaction \"1602849979727\" from \"matrix.org\" containing 1 PDUs, 0 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=LrP2uzWDXjTv req.method=PUT req.path=/_matrix/federation/v1/send/1602849979727
time="2020-10-19T17:09:17.261943212Z" level=info msg="Producing to topic 'DendriteOutputRoomEvent'" func="github.com/matrix-org/dendrite/roomserver/internal/input.(*Inputer).WriteOutputEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/input/input.go:98" adds_state=0 event_id="$1603127356798128JtuMc:matrix.org" event_type=m.room.message removes_state=0 room_id="!EqNTOVyeMgBuVNuVlA:matrix.org" send_as_server="" sender="@freenode_HiPhish:matrix.org" type=new_room_event
time="2020-10-19T17:09:17.263704095Z" level=info msg="Processed 1 PDUs from transaction \"1602849979727\"" func="github.com/matrix-org/dendrite/federationapi/routing.(*txnReq).processTransaction" file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:229" req.id=LrP2uzWDXjTv req.method=PUT req.path=/_matrix/federation/v1/send/1602849979727
time="2020-10-19T17:09:18.006742741Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$YyUFQjqmkE2UNTfgGbh06dXtQg7f3k37mrMDdhqXO84"
time="2020-10-19T17:09:18.815655022Z" level=info msg="Received transaction \"1602035696455\" from \"hackeruniverse.dk\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=zc3FCS5R0wlm req.method=PUT req.path=/_matrix/federation/v1/send/1602035696455
time="2020-10-19T17:09:19.165963536Z" level=info msg="Received transaction \"1602838078939\" from \"planetdecred.org\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=dkWtdSBdhR7e req.method=PUT req.path=/_matrix/federation/v1/send/1602838078939
time="2020-10-19T17:09:19.931778100Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$IVZP2-ag44Qm0fypLSg9kHVAnSB6fa0espDR48QSGD8"
time="2020-10-19T17:09:22.025221348Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$2AI8r-den3CPVvVDOCgnptW6KPhX_XAObCAatByokmI"
time="2020-10-19T17:09:24.477041215Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$G1BXsb0LNDF6qvSdn7Qgcd5xRTthbNCFH7vzMxTnjYQ"
time="2020-10-19T17:09:25.249952209Z" level=info msg="Received transaction \"1603081923649\" from \"beisler.com\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=HWOneO5nFL4T req.method=PUT req.path=/_matrix/federation/v1/send/1603081923649
time="2020-10-19T17:09:26.077465891Z" level=info msg="Received transaction \"1603029816500\" from \"spitetech.com\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=rBqHCDvvjFf3 req.method=PUT req.path=/_matrix/federation/v1/send/1603029816500
time="2020-10-19T17:09:26.426738077Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$wmRNq0FqA0sC_0Omn43RGEnEMLfCvMmpmQ24m2YuKtw"
time="2020-10-19T17:09:27.977544894Z" level=info msg="Received transaction \"1602091757690\" from \"dorthe.us\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=gnnc4358JMzO req.method=PUT req.path=/_matrix/federation/v1/send/1602091757690
time="2020-10-19T17:09:27.994498361Z" level=info msg="Received transaction \"1601886439617\" from \"rdmnn.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=11I8eO3dVJZs req.method=PUT req.path=/_matrix/federation/v1/send/1601886439617
time="2020-10-19T17:09:28.132155315Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$NHvFuBDDdQ28RdCwH_VNekBy9epb2NUyoqu-k8yf3eE"
time="2020-10-19T17:09:28.999850633Z" level=info msg="Received transaction \"1601886440553\" from \"rdmnn.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=KnNnnIld2NxZ req.method=PUT req.path=/_matrix/federation/v1/send/1601886440553
time="2020-10-19T17:09:29.288076110Z" level=info msg="Received transaction \"1602875908989\" from \"envs.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=8T3amY3qY9YC req.method=PUT req.path=/_matrix/federation/v1/send/1602875908989
time="2020-10-19T17:09:29.589439607Z" level=info msg="Received transaction \"1603058556386\" from \"freitrix.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=CDTL9nfB6aHP req.method=PUT req.path=/_matrix/federation/v1/send/1603058556386
time="2020-10-19T17:09:29.674400143Z" level=info msg="Received transaction \"1602361972469\" from \"hillebrand.io\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=LDp1ULePIOZl req.method=PUT req.path=/_matrix/federation/v1/send/1602361972469
time="2020-10-19T17:09:29.720683630Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$Fvt_uTOOe8Xz_0LFvPpznfc6FLw9gurJRmimcyV3bVE"
time="2020-10-19T17:09:30.000741734Z" level=info msg="Received transaction \"1602875909771\" from \"envs.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=veoCeVUdEQ6D req.method=PUT req.path=/_matrix/federation/v1/send/1602875909771
time="2020-10-19T17:09:30.335993085Z" level=info msg="Received transaction \"1603070048809\" from \"tilde.fun\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=MSCCbrK9j3zr req.method=PUT req.path=/_matrix/federation/v1/send/1603070048809
time="2020-10-19T17:09:30.727790012Z" level=info msg="Received transaction \"1602276795958\" from \"lant.uk\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=wvXyvFaaUVex req.method=PUT req.path=/_matrix/federation/v1/send/1602276795958
time="2020-10-19T17:09:30.789668031Z" level=info msg="Received transaction \"1601414569547\" from \"marigold.cafe\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=I1OXVycPQ979 req.method=PUT req.path=/_matrix/federation/v1/send/1601414569547
time="2020-10-19T17:09:31.025925399Z" level=info msg="Received transaction \"1601414572167\" from \"marigold.cafe\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=Les1cI8AQZhe req.method=PUT req.path=/_matrix/federation/v1/send/1601414572167
time="2020-10-19T17:09:31.331532925Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$pV3CcFQT0U2dbRQFvvCONKz8aEgNm0Q1pTuSFhHW5pQ"
time="2020-10-19T17:09:31.921376509Z" level=info msg="Received transaction \"1603103928747\" from \"nimblea.pe\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=4aHKk4svte0h req.method=PUT req.path=/_matrix/federation/v1/send/1603103928747
time="2020-10-19T17:09:32.045387365Z" level=info msg="Received transaction \"1601995025052\" from \"schwifty.earth\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=TsqjRIHzTZtc req.method=PUT req.path=/_matrix/federation/v1/send/1601995025052
time="2020-10-19T17:09:32.198217302Z" level=info msg="Received transaction \"1603091373796\" from \"matrix.lrn.fm\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=31TsV046XfHa req.method=PUT req.path=/_matrix/federation/v1/send/1603091373796
time="2020-10-19T17:09:32.545639729Z" level=info msg="Received transaction \"1602898148116\" from \"s3cr3t.me\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=8u2jj0umKBBj req.method=PUT req.path=/_matrix/federation/v1/send/1602898148116
time="2020-10-19T17:09:32.586631838Z" level=info msg="Received transaction \"1601500821107\" from \"sw1v.org\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=bF8v7DngnokM req.method=PUT req.path=/_matrix/federation/v1/send/1601500821107
time="2020-10-19T17:09:32.771610793Z" level=info msg="Received transaction \"1603122034301\" from \"callchat.xyz\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=KJclVXMdpUS7 req.method=PUT req.path=/_matrix/federation/v1/send/1603122034301
time="2020-10-19T17:09:32.886715308Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$WMliGkMeC87NxfUi83HJc02feEs9gTFDtM5YYT810Ww"
time="2020-10-19T17:09:32.969875102Z" level=info msg="Received transaction \"1602361973530\" from \"hillebrand.io\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=l4WkiDN3sXOm req.method=PUT req.path=/_matrix/federation/v1/send/1602361973530
time="2020-10-19T17:09:33.181864538Z" level=info msg="Received transaction \"1602276797150\" from \"lant.uk\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=nC5m5cVLtWp1 req.method=PUT req.path=/_matrix/federation/v1/send/1602276797150
time="2020-10-19T17:09:33.221974475Z" level=info msg="Received transaction \"1603103929862\" from \"nimblea.pe\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=X5Go7xRfHawc req.method=PUT req.path=/_matrix/federation/v1/send/1603103929862
time="2020-10-19T17:09:33.690140005Z" level=info msg="Received transaction \"1603122035902\" from \"callchat.xyz\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=eeXKuUBzaAJ7 req.method=PUT req.path=/_matrix/federation/v1/send/1603122035902
time="2020-10-19T17:09:33.887299680Z" level=info msg="Received transaction \"1602736799114\" from \"typ3.tech\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=QzppRPkqhHBG req.method=PUT req.path=/_matrix/federation/v1/send/1602736799114
time="2020-10-19T17:09:34.321236200Z" level=info msg="Received transaction \"1602849980066\" from \"matrix.org\" containing 0 PDUs, 2 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=BpnzLGknRP7U req.method=PUT req.path=/_matrix/federation/v1/send/1602849980066
time="2020-10-19T17:09:34.322326341Z" level=info msg=DeviceListUpdater.Update func="github.com/matrix-org/dendrite/keyserver/internal.(*DeviceListUpdater).update" file="github.com/matrix-org/dendrite@/keyserver/internal/device_list_update.go:201" context=missing deleted=false device_id=INRASCKFZV display_name="Element Desktop (Linux)" prev_ids="[390963439]" prev_ids_exist=false stream_id=390964021 user_id="@debian-user:matrix.org"
time="2020-10-19T17:09:34.504876679Z" level=info msg="Produced to key change topic 'DendriteOutputKeyChangeEvent'" func="github.com/matrix-org/dendrite/keyserver/producers.(*KeyChange).ProduceKeyChanges" file="github.com/matrix-org/dendrite@/keyserver/producers/keychange.go:72" num_key_changes=1 user_id="@debian-user:matrix.org"
time="2020-10-19T17:09:34.646240640Z" level=info msg="Received transaction \"1602192257845\" from \"not420chan.org\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=LQ5acHv3NaWS req.method=PUT req.path=/_matrix/federation/v1/send/1602192257845
time="2020-10-19T17:09:34.789612727Z" level=info msg="Received transaction \"1602276797730\" from \"lant.uk\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=oGWFcJzIz0d9 req.method=PUT req.path=/_matrix/federation/v1/send/1602276797730
time="2020-10-19T17:09:34.946852021Z" level=info msg="Received transaction \"1602849980139\" from \"matrix.org\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=RqzDTGZ0xBLc req.method=PUT req.path=/_matrix/federation/v1/send/1602849980139
time="2020-10-19T17:09:35.086447665Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$7Ouo4t-ndFNnBlIxZDj2lKMs_qKccaKKG666gSTp748"
time="2020-10-19T17:09:35.423006395Z" level=info msg="Received transaction \"1603103930341\" from \"nimblea.pe\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=lgRQ1mBI8fOl req.method=PUT req.path=/_matrix/federation/v1/send/1603103930341
time="2020-10-19T17:09:36.646001342Z" level=info msg="Received transaction \"1602736800440\" from \"typ3.tech\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=2uwIiPpJ7ukd req.method=PUT req.path=/_matrix/federation/v1/send/1602736800440
time="2020-10-19T17:09:36.892575331Z" level=info msg="Received transaction \"1602691316289\" from \"bau-ha.us\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=a8FeQ0WPpWdg req.method=PUT req.path=/_matrix/federation/v1/send/1602691316289
time="2020-10-19T17:09:36.956187499Z" level=info msg="Received transaction \"1603103931375\" from \"nimblea.pe\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=GpPsGNti1Y35 req.method=PUT req.path=/_matrix/federation/v1/send/1603103931375
time="2020-10-19T17:09:37.219609130Z" level=info msg="Received transaction \"1602849980279\" from \"matrix.org\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=EUzNjuITCU47 req.method=PUT req.path=/_matrix/federation/v1/send/1602849980279
time="2020-10-19T17:09:37.220642956Z" level=info msg=DeviceListUpdater.Update func="github.com/matrix-org/dendrite/keyserver/internal.(*DeviceListUpdater).update" file="github.com/matrix-org/dendrite@/keyserver/internal/device_list_update.go:201" context=missing deleted=false device_id=INRASCKFZV display_name="Element Desktop (Linux)" prev_ids="[390964022]" prev_ids_exist=false stream_id=390964970 user_id="@debian-user:matrix.org"
time="2020-10-19T17:09:37.523612152Z" level=info msg="Received transaction \"1602849980362\" from \"matrix.org\" containing 1 PDUs, 0 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=klrNdUPFfuZT req.method=PUT req.path=/_matrix/federation/v1/send/1602849980362
time="2020-10-19T17:09:37.524388641Z" level=warning msg="Transaction: Failed to query room version for room!XaqDhxuTIlvldquJaV:matrix.org" func="github.com/matrix-org/dendrite/federationapi/routing.(*txnReq).processTransaction" file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:145" error="QueryRoomVersionForRoom: missing room info for room !XaqDhxuTIlvldquJaV:matrix.org" req.id=klrNdUPFfuZT req.method=PUT req.path=/_matrix/federation/v1/send/1602849980362
time="2020-10-19T17:09:37.690775456Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$uSuuSZP1YPb_JvKVu7-PiSuDk4IzfXbgbCclxvzZSXI"
time="2020-10-19T17:09:37.970752456Z" level=info msg="Received transaction \"1601500822726\" from \"sw1v.org\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=IbxaN54Midhc req.method=PUT req.path=/_matrix/federation/v1/send/1601500822726
time="2020-10-19T17:09:38.876109647Z" level=info msg="Received transaction \"1602962470482\" from \"ingwie.io\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=rZUDbXhsWwqd req.method=PUT req.path=/_matrix/federation/v1/send/1602962470482
time="2020-10-19T17:09:39.137161167Z" level=info msg="Received transaction \"1603085182761\" from \"matrix.underworld.fr\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=5uxbJMFRi7BC req.method=PUT req.path=/_matrix/federation/v1/send/1603085182761
time="2020-10-19T17:09:39.706504682Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$KwucN5T5oiyJMjbTa38KTMBmPFuRpA2tP5nTCA9hy8U"
time="2020-10-19T17:09:40.085388221Z" level=info msg="Received transaction \"1601428559217\" from \"matrix.amoebacolony.com\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=Rh43CQWodmmD req.method=PUT req.path=/_matrix/federation/v1/send/1601428559217
time="2020-10-19T17:09:41.338764361Z" level=info msg="Received transaction \"1603123967898\" from \"finallycoffee.eu\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=SBXqqoEFbvIZ req.method=PUT req.path=/_matrix/federation/v1/send/1603123967898
time="2020-10-19T17:09:41.363100774Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$N-s8GGqjKuMSp04LxTmqSCU6BUI151sx196m1WMbE2k"
time="2020-10-19T17:09:43.104355498Z" level=info msg="Received transaction \"1603067971031\" from \"matrix.trineo.org\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=Dzxhxa4YikOu req.method=PUT req.path=/_matrix/federation/v1/send/1603067971031
time="2020-10-19T17:09:43.547216597Z" level=info msg="Received transaction \"1603123970371\" from \"finallycoffee.eu\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=Hv08lgYyBLaT req.method=PUT req.path=/_matrix/federation/v1/send/1603123970371
time="2020-10-19T17:09:43.574118560Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$iM5GQFvCk3kFzYlHmMib_Wo2xhtcB17c4htbRKVamCU"
time="2020-10-19T17:09:44.257777831Z" level=info msg="Received transaction \"1603067971921\" from \"matrix.trineo.org\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=QoT4qIEvPCGC req.method=PUT req.path=/_matrix/federation/v1/send/1603067971921
time="2020-10-19T17:09:44.614347552Z" level=info msg="Received transaction \"1602843193901\" from \"nitro.chat\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=yA3XkBvUZ3CF req.method=PUT req.path=/_matrix/federation/v1/send/1602843193901
time="2020-10-19T17:09:45.192471635Z" level=info msg="Received transaction \"1602849980681\" from \"matrix.org\" containing 1 PDUs, 0 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=XDr2qlgF01ow req.method=PUT req.path=/_matrix/federation/v1/send/1602849980681
time="2020-10-19T17:09:45.242338170Z" level=info msg="Producing to topic 'DendriteOutputRoomEvent'" func="github.com/matrix-org/dendrite/roomserver/internal/input.(*Inputer).WriteOutputEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/input/input.go:98" adds_state=0 event_id="$1603127382798244Heksm:matrix.org" event_type=m.room.message removes_state=0 room_id="!EqNTOVyeMgBuVNuVlA:matrix.org" send_as_server="" sender="@freenode_nonchip:matrix.org" type=new_room_event
time="2020-10-19T17:09:45.244430416Z" level=info msg="Processed 1 PDUs from transaction \"1602849980681\"" func="github.com/matrix-org/dendrite/federationapi/routing.(*txnReq).processTransaction" file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:229" req.id=XDr2qlgF01ow req.method=PUT req.path=/_matrix/federation/v1/send/1602849980681
time="2020-10-19T17:09:45.390146288Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$Pz8PByNHTrgFwc73wQivv0haCwMG73-Y_vdl0rp3sUg"
time="2020-10-19T17:09:45.815404240Z" level=info msg="Received transaction \"1603045745433\" from \"elsmussols.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=wM7xVL1xLsn3 req.method=PUT req.path=/_matrix/federation/v1/send/1603045745433
time="2020-10-19T17:09:46.370093319Z" level=info msg="Received transaction \"1602931986845\" from \"matrix.fff.community\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=vDOJacLd0GZg req.method=PUT req.path=/_matrix/federation/v1/send/1602931986845
time="2020-10-19T17:09:46.681943666Z" level=info msg="Received transaction \"1602035697064\" from \"hackeruniverse.dk\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=HxrZWOrKDRrK req.method=PUT req.path=/_matrix/federation/v1/send/1602035697064
time="2020-10-19T17:09:46.725299255Z" level=info msg="Received transaction \"1602931987194\" from \"matrix.fff.community\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=cXAYaRcVtWSU req.method=PUT req.path=/_matrix/federation/v1/send/1602931987194
time="2020-10-19T17:09:46.929792199Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$Zb9fe9gWRfX-Tx6Z6bthTHPfwo8FZufZ4FyabRmyF0o"
time="2020-10-19T17:09:48.493938806Z" level=info msg="Received transaction \"1603058556478\" from \"freitrix.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=uxwEYs9uYpSd req.method=PUT req.path=/_matrix/federation/v1/send/1603058556478
time="2020-10-19T17:09:48.952307225Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$6Jb9SdgQmPakvIReAoyK3uYrSjBvWkxuDT7m1hSmCsk"
time="2020-10-19T17:09:49.800427617Z" level=info msg="Received transaction \"1602778996813\" from \"isomemetric.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=kic4g1WUEUaf req.method=PUT req.path=/_matrix/federation/v1/send/1602778996813
time="2020-10-19T17:09:49.898148298Z" level=info msg="Received transaction \"1602778999023\" from \"isomemetric.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=ex15QkLGr3Em req.method=PUT req.path=/_matrix/federation/v1/send/1602778999023
time="2020-10-19T17:09:50.144012577Z" level=info msg="Received transaction \"1602844509612\" from \"im.kabi.tk\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=By1mBzikRK5P req.method=PUT req.path=/_matrix/federation/v1/send/1602844509612
time="2020-10-19T17:09:50.514226470Z" level=info msg="Received transaction \"1603045746588\" from \"elsmussols.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=uToPO9unYOcU req.method=PUT req.path=/_matrix/federation/v1/send/1603045746588
time="2020-10-19T17:09:52.698175700Z" level=info msg="Received transaction \"1601688857118\" from \"antonok.com\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=EA52jThLsIcL req.method=PUT req.path=/_matrix/federation/v1/send/1601688857118
time="2020-10-19T17:09:52.984733331Z" level=info msg="Received transaction \"1602844510736\" from \"im.kabi.tk\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=RI3XY0tZGTzk req.method=PUT req.path=/_matrix/federation/v1/send/1602844510736
time="2020-10-19T17:09:53.335998459Z" level=info msg="Received transaction \"1601207216515\" from \"matrix.altay.fr\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=1bMJnyvUqyGO req.method=PUT req.path=/_matrix/federation/v1/send/1601207216515
time="2020-10-19T17:09:53.582021819Z" level=info msg="Received transaction \"1602361974367\" from \"hillebrand.io\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=QqLkjaLfCp3B req.method=PUT req.path=/_matrix/federation/v1/send/1602361974367
time="2020-10-19T17:09:55.251084356Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$ZHZNdBZ8mHlmDNPEGLwOyaoxDWmseBsl3ohUuC_rtQc"
time="2020-10-19T17:09:55.734619428Z" level=info msg="Received transaction \"1601806440939\" from \"jaccu.se\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=5UqQtti8UORm req.method=PUT req.path=/_matrix/federation/v1/send/1601806440939
time="2020-10-19T17:09:55.843836216Z" level=info msg="Received transaction \"1602361975454\" from \"hillebrand.io\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=gp3Vkp7X18JT req.method=PUT req.path=/_matrix/federation/v1/send/1602361975454
time="2020-10-19T17:09:57.029663019Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$cWOXMFbcIMQIX3qNz4mwnit69EdGEw3vDWhk01ZkJNI"
time="2020-10-19T17:09:58.439636097Z" level=info msg="Received transaction \"1602773609481\" from \"matrix.un-hack-bar.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=NwuMmoA0dtbK req.method=PUT req.path=/_matrix/federation/v1/send/1602773609481
time="2020-10-19T17:09:58.464208271Z" level=info msg="Received transaction \"1602773609861\" from \"matrix.un-hack-bar.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=DlrDeTxMJuUh req.method=PUT req.path=/_matrix/federation/v1/send/1602773609861
time="2020-10-19T17:09:58.816974647Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$eE5C7HZbBlrPt-JE8dzYq_SRGTUAapWcNoGNELifIp8"
time="2020-10-19T17:10:00.255357033Z" level=info msg="Received transaction \"1602969812880\" from \"chat.avlikos.gr\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=Ep5IpHbXGamg req.method=PUT req.path=/_matrix/federation/v1/send/1602969812880
time="2020-10-19T17:10:00.521436012Z" level=info msg="Received transaction \"1602781448807\" from \"magnumchaos.org\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=5abfmpPhUb4q req.method=PUT req.path=/_matrix/federation/v1/send/1602781448807
time="2020-10-19T17:10:01.577671310Z" level=info msg="Received transaction \"1602809439574\" from \"matrix.kenzi.dev\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=nAvpi9fDZSSd req.method=PUT req.path=/_matrix/federation/v1/send/1602809439574
time="2020-10-19T17:10:01.626409542Z" level=info msg="Received transaction \"1602941264842\" from \"thebeckmeyers.xyz\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=jeWeIVpOAuvA req.method=PUT req.path=/_matrix/federation/v1/send/1602941264842
time="2020-10-19T17:10:02.137608938Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$_9imtXpxsy0qz0jnYFa3-CqzQU4gga4VqRLXFGAa0uM"
time="2020-10-19T17:10:02.605903296Z" level=info msg="Received transaction \"1602809441200\" from \"matrix.kenzi.dev\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=DD4b3z4zGW0e req.method=PUT req.path=/_matrix/federation/v1/send/1602809441200
time="2020-10-19T17:10:02.619817854Z" level=info msg="Received transaction \"1602941265401\" from \"thebeckmeyers.xyz\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=qOzYl6JrOO5r req.method=PUT req.path=/_matrix/federation/v1/send/1602941265401
time="2020-10-19T17:10:04.053636752Z" level=info msg="Received transaction \"1603123971263\" from \"finallycoffee.eu\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=KhhysVwAhAFr req.method=PUT req.path=/_matrix/federation/v1/send/1603123971263
time="2020-10-19T17:10:04.063145330Z" level=info msg="Received transaction \"1600770960420\" from \"riot.firechicken.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=TDaWkotDkT1D req.method=PUT req.path=/_matrix/federation/v1/send/1600770960420
time="2020-10-19T17:10:04.459580652Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$xp6JetAyq2aL08_MC94LO7ju43lgeYP01809LYZj4iE"
time="2020-10-19T17:10:04.506758147Z" level=info msg="Received transaction \"1600770961394\" from \"riot.firechicken.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=36Pi337IL7Xe req.method=PUT req.path=/_matrix/federation/v1/send/1600770961394
time="2020-10-19T17:10:04.690181429Z" level=info msg="Received transaction \"1603123801477\" from \"bubu1.eu\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=BurtHBO7lqtf req.method=PUT req.path=/_matrix/federation/v1/send/1603123801477
time="2020-10-19T17:10:06.164473479Z" level=info msg="Received transaction \"1603074062611\" from \"matrix.cccgoe.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=XoCoiKqpPJYa req.method=PUT req.path=/_matrix/federation/v1/send/1603074062611
time="2020-10-19T17:10:06.311937439Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$R3TaCG3TjhY5VC8aHCJpJeztDDKad6sx2P1imDr13Vc"
time="2020-10-19T17:10:06.447636953Z" level=info msg="Received transaction \"1602776612026\" from \"maunium.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=IPsZBt1JzFyK req.method=PUT req.path=/_matrix/federation/v1/send/1602776612026
time="2020-10-19T17:10:07.107661710Z" level=info msg="Received transaction \"1602636931461\" from \"arkmuse.org\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=aG4PYbtkDzJU req.method=PUT req.path=/_matrix/federation/v1/send/1602636931461
time="2020-10-19T17:10:08.299898086Z" level=info msg="Received transaction \"1602786311518\" from \"lost-frequencies.eu\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=qbiNxTliDIQg req.method=PUT req.path=/_matrix/federation/v1/send/1602786311518
time="2020-10-19T17:10:08.314860598Z" level=info msg="Received transaction \"1602786313220\" from \"lost-frequencies.eu\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=tpXVlA3gueew req.method=PUT req.path=/_matrix/federation/v1/send/1602786313220
time="2020-10-19T17:10:08.345406751Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$lEcdnyMHrmSTnH_7MVetbEShdD2MjHJRQGQNJkXY3bA"
time="2020-10-19T17:10:09.164179202Z" level=info msg="Received transaction \"1603107602847\" from \"gruenhage.xyz\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=juB29QfJdcCc req.method=PUT req.path=/_matrix/federation/v1/send/1603107602847
time="2020-10-19T17:10:09.842565630Z" level=info msg="Received transaction \"1602867692993\" from \"cofree.coffee\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=nV0Yb7kx6rBb req.method=PUT req.path=/_matrix/federation/v1/send/1602867692993
time="2020-10-19T17:10:09.997290543Z" level=info msg="Received transaction \"1602867694137\" from \"cofree.coffee\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=tTIvIyH62xb6 req.method=PUT req.path=/_matrix/federation/v1/send/1602867694137
time="2020-10-19T17:10:10.397307824Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$DJ1u92RKURMWu_iUe6cqmBSVr61IOWKPyEjm8MVsCJA"
time="2020-10-19T17:10:11.261362416Z" level=info msg="Received transaction \"1603123186384\" from \"mawalabs.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=SAvljUkCoJTE req.method=PUT req.path=/_matrix/federation/v1/send/1603123186384
time="2020-10-19T17:10:11.551756593Z" level=info msg="Received transaction \"1602849981132\" from \"matrix.org\" containing 0 PDUs, 2 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=kDsow5m56dkY req.method=PUT req.path=/_matrix/federation/v1/send/1602849981132
time="2020-10-19T17:10:11.551976045Z" level=info msg="Producing to topic 'DendriteOutputTypingEvent'" func="github.com/matrix-org/dendrite/eduserver/input.(*EDUServerInputAPI).sendTypingEvent" file="github.com/matrix-org/dendrite@/eduserver/input/input.go:104" room_id="!XaqDhxuTIlvldquJaV:matrix.org" typing=true user_id="@clokep:matrix.org"
time="2020-10-19T17:10:11.555699075Z" level=info msg="Suppressing typing notif: originated elsewhere" func="github.com/matrix-org/dendrite/federationsender/consumers.(*OutputEDUConsumer).onTypingEvent" file="github.com/matrix-org/dendrite@/federationsender/consumers/eduserver.go:155" other_server=matrix.org
time="2020-10-19T17:10:12.220054200Z" level=info msg="Received transaction \"1601245772062\" from \"mastodon.se\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=bBbCvJexqysF req.method=PUT req.path=/_matrix/federation/v1/send/1601245772062
time="2020-10-19T17:10:12.413251638Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$uFqZprP3NPa8NBRNMals9ucjdSMRnd9R_QQl-SMX9fs"
time="2020-10-19T17:10:12.828382527Z" level=info msg="Received transaction \"1603123186995\" from \"mawalabs.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=cW5ECU5v2ptz req.method=PUT req.path=/_matrix/federation/v1/send/1603123186995
time="2020-10-19T17:10:13.384762972Z" level=info msg="Received transaction \"1602779775656\" from \"hnitbjorg.xyz\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=DdCCGc0Xg7e2 req.method=PUT req.path=/_matrix/federation/v1/send/1602779775656
time="2020-10-19T17:10:13.532540003Z" level=info msg="Received transaction \"1602778327055\" from \"imninja.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=X97uGPeZclo9 req.method=PUT req.path=/_matrix/federation/v1/send/1602778327055
time="2020-10-19T17:10:13.799688335Z" level=info msg="Received transaction \"1602875910150\" from \"envs.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=HsPQZWX8ZEu2 req.method=PUT req.path=/_matrix/federation/v1/send/1602875910150
time="2020-10-19T17:10:14.766890174Z" level=info msg="Received transaction \"1602875911083\" from \"envs.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=6fvqSCWY4qoi req.method=PUT req.path=/_matrix/federation/v1/send/1602875911083
time="2020-10-19T17:10:14.811407411Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$nXpsaoM-ikLgKW0eWs-kOIM0DHJ3xwqrCR9tMhNWSuY"
time="2020-10-19T17:10:14.911798858Z" level=info msg="Received transaction \"1602792821931\" from \"starritt.dev\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=ClfFksJH2tk1 req.method=PUT req.path=/_matrix/federation/v1/send/1602792821931
time="2020-10-19T17:10:15.038229142Z" level=info msg="Received transaction \"1602792823251\" from \"starritt.dev\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=LlbYUTNYusm9 req.method=PUT req.path=/_matrix/federation/v1/send/1602792823251
time="2020-10-19T17:10:15.666702568Z" level=info msg="Received transaction \"1602440483718\" from \"hackers.town\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=g4fAZWDwcOvo req.method=PUT req.path=/_matrix/federation/v1/send/1602440483718
time="2020-10-19T17:10:17.332459632Z" level=info msg="Received transaction \"1602849981208\" from \"matrix.org\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=eWuYYVyHnBhU req.method=PUT req.path=/_matrix/federation/v1/send/1602849981208
time="2020-10-19T17:10:17.332715237Z" level=info msg="Producing to topic 'DendriteOutputTypingEvent'" func="github.com/matrix-org/dendrite/eduserver/input.(*EDUServerInputAPI).sendTypingEvent" file="github.com/matrix-org/dendrite@/eduserver/input/input.go:104" room_id="!XaqDhxuTIlvldquJaV:matrix.org" typing=false user_id="@clokep:matrix.org"
time="2020-10-19T17:10:17.336098629Z" level=info msg="Suppressing typing notif: originated elsewhere" func="github.com/matrix-org/dendrite/federationsender/consumers.(*OutputEDUConsumer).onTypingEvent" file="github.com/matrix-org/dendrite@/federationsender/consumers/eduserver.go:155" other_server=matrix.org
time="2020-10-19T17:10:17.725229553Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$K41d2djhkRimZhdIaFv45RjqzK6dGDSbg5zXMHuIDBw"
time="2020-10-19T17:10:17.729002147Z" level=info msg="Received transaction \"1602849981221\" from \"matrix.org\" containing 1 PDUs, 0 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=kbQ6vIIJTUKz req.method=PUT req.path=/_matrix/federation/v1/send/1602849981221
time="2020-10-19T17:10:17.748882964Z" level=info msg="Producing to topic 'DendriteOutputRoomEvent'" func="github.com/matrix-org/dendrite/roomserver/internal/input.(*Inputer).WriteOutputEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/input/input.go:98" adds_state=0 event_id="$1603127412798384KeCMc:matrix.org" event_type=m.room.message removes_state=0 room_id="!EqNTOVyeMgBuVNuVlA:matrix.org" send_as_server="" sender="@freenode_ericonr:matrix.org" type=new_room_event
time="2020-10-19T17:10:17.750732909Z" level=info msg="Processed 1 PDUs from transaction \"1602849981221\"" func="github.com/matrix-org/dendrite/federationapi/routing.(*txnReq).processTransaction" file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:229" req.id=kbQ6vIIJTUKz req.method=PUT req.path=/_matrix/federation/v1/send/1602849981221
time="2020-10-19T17:10:18.338281182Z" level=info msg="Received transaction \"1603124818464\" from \"vector.modular.im\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=Q2jykbE0KUMV req.method=PUT req.path=/_matrix/federation/v1/send/1603124818464
time="2020-10-19T17:10:18.733867493Z" level=info msg="Received transaction \"1602035697644\" from \"hackeruniverse.dk\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=kMJfdEHViMvw req.method=PUT req.path=/_matrix/federation/v1/send/1602035697644
time="2020-10-19T17:10:20.127438018Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$SDu3hedTo_4ABiYvPJX_Ne3aA5uUubDUSvqwfyQi42s"
time="2020-10-19T17:10:20.727144151Z" level=info msg="Received transaction \"1601293745042\" from \"matrix.klass.biz\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=Bb9j543FvHie req.method=PUT req.path=/_matrix/federation/v1/send/1601293745042
time="2020-10-19T17:10:20.746696711Z" level=info msg="Received transaction \"1603079366501\" from \"janian.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=wKKxdq4t8UX0 req.method=PUT req.path=/_matrix/federation/v1/send/1603079366501
time="2020-10-19T17:10:21.366972611Z" level=info msg="Received transaction \"1603045747764\" from \"elsmussols.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=sWYZUFStIyy3 req.method=PUT req.path=/_matrix/federation/v1/send/1603045747764
time="2020-10-19T17:10:22.329094771Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$GO1I0GRHuiLgq8fDDkzWxe_eV3zhrzwzclfoSlnpdRs"
time="2020-10-19T17:10:23.615237194Z" level=info msg="Received transaction \"1600913975541\" from \"goosetech.pro\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=xG3N6D3C8NCC req.method=PUT req.path=/_matrix/federation/v1/send/1600913975541
time="2020-10-19T17:10:23.739437465Z" level=info msg="Received transaction \"1600913977097\" from \"goosetech.pro\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=D9pcjyqtNAFP req.method=PUT req.path=/_matrix/federation/v1/send/1600913977097
time="2020-10-19T17:10:25.389445955Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$AjsxiNpjkFVpKROp40cnwncJDBvhtWOm-8R_Wp42np4"
time="2020-10-19T17:10:25.677222886Z" level=info msg="Received transaction \"1603103931890\" from \"nimblea.pe\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=iORdbKYafrsi req.method=PUT req.path=/_matrix/federation/v1/send/1603103931890
time="2020-10-19T17:10:25.708681248Z" level=info msg="Received transaction \"1603124820223\" from \"vector.modular.im\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=gftDa3HUgpdt req.method=PUT req.path=/_matrix/federation/v1/send/1603124820223
time="2020-10-19T17:10:25.720892388Z" level=info msg="Received transaction \"1601688857275\" from \"antonok.com\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=wft6snsk4DSY req.method=PUT req.path=/_matrix/federation/v1/send/1601688857275
time="2020-10-19T17:10:25.761713647Z" level=info msg="Received transaction \"1602849981401\" from \"matrix.org\" containing 1 PDUs, 0 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=MZXYm383hW0S req.method=PUT req.path=/_matrix/federation/v1/send/1602849981401
time="2020-10-19T17:10:25.762477412Z" level=warning msg="Transaction: Failed to query room version for room!XaqDhxuTIlvldquJaV:matrix.org" func="github.com/matrix-org/dendrite/federationapi/routing.(*txnReq).processTransaction" file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:145" error="QueryRoomVersionForRoom: missing room info for room !XaqDhxuTIlvldquJaV:matrix.org" req.id=MZXYm383hW0S req.method=PUT req.path=/_matrix/federation/v1/send/1602849981401
time="2020-10-19T17:10:26.743205458Z" level=info msg="Received transaction \"1603045748863\" from \"elsmussols.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=j39sXUO4zlnR req.method=PUT req.path=/_matrix/federation/v1/send/1603045748863
time="2020-10-19T17:10:29.298480809Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$JIoteOHPlieKzR6ZiGm5CLtCodT8Q8DeeZK0udESoeo"
time="2020-10-19T17:10:30.017714346Z" level=info msg="Received transaction \"1603124821782\" from \"vector.modular.im\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=JtB8bUoZBXCg req.method=PUT req.path=/_matrix/federation/v1/send/1603124821782
time="2020-10-19T17:10:31.784324334Z" level=info msg="Received transaction \"1602886962099\" from \"mssj.me\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=QpOapF7V93XP req.method=PUT req.path=/_matrix/federation/v1/send/1602886962099
time="2020-10-19T17:10:31.789702519Z" level=info msg="Received transaction \"1602710033752\" from \"trolla.us\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=FWgrnymVMI0N req.method=PUT req.path=/_matrix/federation/v1/send/1602710033752
time="2020-10-19T17:10:31.959301630Z" level=info msg="Received transaction \"1602886963681\" from \"mssj.me\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=T5djQBbluPmD req.method=PUT req.path=/_matrix/federation/v1/send/1602886963681
time="2020-10-19T17:10:32.011352198Z" level=info msg="Received transaction \"1603125907553\" from \"rakor.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=vZh29myW23EO req.method=PUT req.path=/_matrix/federation/v1/send/1603125907553
time="2020-10-19T17:10:32.189827402Z" level=info msg="Received transaction \"1602775237988\" from \"matrix.sp-codes.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=bigj8sqjryMk req.method=PUT req.path=/_matrix/federation/v1/send/1602775237988
time="2020-10-19T17:10:32.647146445Z" level=info msg="Received transaction \"1602610764111\" from \"matrix.somewhatspatial.com\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=LvFQFRPufTsp req.method=PUT req.path=/_matrix/federation/v1/send/1602610764111
time="2020-10-19T17:10:32.868418157Z" level=info msg="Received transaction \"1602849981530\" from \"matrix.org\" containing 1 PDUs, 0 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=Ry3otGAmbWfx req.method=PUT req.path=/_matrix/federation/v1/send/1602849981530
time="2020-10-19T17:10:32.869263602Z" level=warning msg="Transaction: Failed to query room version for room!UMOdWVcgceMwDXgWtC:matrix.org" func="github.com/matrix-org/dendrite/federationapi/routing.(*txnReq).processTransaction" file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:145" error="QueryRoomVersionForRoom: missing room info for room !UMOdWVcgceMwDXgWtC:matrix.org" req.id=Ry3otGAmbWfx req.method=PUT req.path=/_matrix/federation/v1/send/1602849981530
time="2020-10-19T17:10:33.097527248Z" level=info msg="Received transaction \"1602361976163\" from \"hillebrand.io\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=RW1nQXcg6w44 req.method=PUT req.path=/_matrix/federation/v1/send/1602361976163
time="2020-10-19T17:10:33.135607974Z" level=info msg="Received transaction \"1603125908724\" from \"rakor.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=rqfEnZgoyp1O req.method=PUT req.path=/_matrix/federation/v1/send/1603125908724
time="2020-10-19T17:10:33.450925918Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$s4rUAKh-1a51zybvI9ZaYUYlTKPXIS3OMeesCMbdTco"
time="2020-10-19T17:10:33.482632142Z" level=info msg="Received transaction \"1602775239786\" from \"matrix.sp-codes.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=3NDyFtTmWiH6 req.method=PUT req.path=/_matrix/federation/v1/send/1602775239786
time="2020-10-19T17:10:34.826179037Z" level=info msg="Received transaction \"1601729223935\" from \"matrix.unbl.ink\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=hIVpgYzEmkSE req.method=PUT req.path=/_matrix/federation/v1/send/1601729223935
time="2020-10-19T17:10:35.029507392Z" level=info msg="Received transaction \"1602361977250\" from \"hillebrand.io\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=QCcnu4Kg0ZLr req.method=PUT req.path=/_matrix/federation/v1/send/1602361977250
time="2020-10-19T17:10:36.293917660Z" level=info msg="Received transaction \"1603123973211\" from \"finallycoffee.eu\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=GNdbmXsIuaQG req.method=PUT req.path=/_matrix/federation/v1/send/1603123973211
time="2020-10-19T17:10:36.558704004Z" level=info msg="Received transaction \"1602625791350\" from \"agnos.is\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=oH4aWlEcd7jS req.method=PUT req.path=/_matrix/federation/v1/send/1602625791350
time="2020-10-19T17:10:36.826561034Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$evSzxWo3Tkkq8ZMCdF9pW0JeSXiHXwAGMBy7yjf50c0"
time="2020-10-19T17:10:39.568288732Z" level=info msg="Received transaction \"1603058556561\" from \"freitrix.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=NCLylPqmQvPq req.method=PUT req.path=/_matrix/federation/v1/send/1603058556561
time="2020-10-19T17:10:39.631190138Z" level=info msg="Received transaction \"1602872152267\" from \"threeraccoons.xyz\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=56MpHGFwCIIe req.method=PUT req.path=/_matrix/federation/v1/send/1602872152267
time="2020-10-19T17:10:39.668944594Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$cigZ4tuNqL5FzrjRopkh5tN_SDpVZ3moVI31jjZFte8"
time="2020-10-19T17:10:40.378465671Z" level=info msg="Received transaction \"1602849981663\" from \"matrix.org\" containing 0 PDUs, 2 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=RlP4WhwBpjsG req.method=PUT req.path=/_matrix/federation/v1/send/1602849981663
time="2020-10-19T17:10:40.379470759Z" level=info msg=DeviceListUpdater.Update func="github.com/matrix-org/dendrite/keyserver/internal.(*DeviceListUpdater).update" file="github.com/matrix-org/dendrite@/keyserver/internal/device_list_update.go:201" context=missing deleted=false device_id=SWMIORXGHH display_name="app.element.io (Chrome, Windows)" prev_ids="[]" prev_ids_exist=false stream_id=390970396 user_id="@hermine.fierbinteanu:matrix.org"
time="2020-10-19T17:10:40.463862610Z" level=info msg="Produced to key change topic 'DendriteOutputKeyChangeEvent'" func="github.com/matrix-org/dendrite/keyserver/producers.(*KeyChange).ProduceKeyChanges" file="github.com/matrix-org/dendrite@/keyserver/producers/keychange.go:72" num_key_changes=1 user_id="@hermine.fierbinteanu:matrix.org"
time="2020-10-19T17:10:42.279759782Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$sXQGw2Hft2eae1-qbY1cCWOxhRfm96f9kD4mllB-xeI"
time="2020-10-19T17:10:42.696791283Z" level=info msg="Received transaction \"1602849981794\" from \"matrix.org\" containing 1 PDUs, 0 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=5vWcDWplVTU0 req.method=PUT req.path=/_matrix/federation/v1/send/1602849981794
time="2020-10-19T17:10:42.716954157Z" level=info msg="Producing to topic 'DendriteOutputRoomEvent'" func="github.com/matrix-org/dendrite/roomserver/internal/input.(*Inputer).WriteOutputEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/input/input.go:98" adds_state=0 event_id="$1603127439798470GoBcx:matrix.org" event_type=m.room.message removes_state=0 room_id="!EqNTOVyeMgBuVNuVlA:matrix.org" send_as_server="" sender="@freenode_ericonr:matrix.org" type=new_room_event
time="2020-10-19T17:10:42.718590116Z" level=info msg="Processed 1 PDUs from transaction \"1602849981794\"" func="github.com/matrix-org/dendrite/federationapi/routing.(*txnReq).processTransaction" file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:229" req.id=5vWcDWplVTU0 req.method=PUT req.path=/_matrix/federation/v1/send/1602849981794
time="2020-10-19T17:10:43.422144071Z" level=info msg="Received transaction \"1601500823489\" from \"sw1v.org\" containing 0 PDUs, 2 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=4YT1mgbSInBS req.method=PUT req.path=/_matrix/federation/v1/send/1601500823489
time="2020-10-19T17:10:43.422318805Z" level=info msg="Producing to topic 'DendriteOutputTypingEvent'" func="github.com/matrix-org/dendrite/eduserver/input.(*EDUServerInputAPI).sendTypingEvent" file="github.com/matrix-org/dendrite@/eduserver/input/input.go:104" room_id="!XaqDhxuTIlvldquJaV:matrix.org" typing=true user_id="@richvdh:sw1v.org"
time="2020-10-19T17:10:43.426410020Z" level=info msg="Suppressing typing notif: originated elsewhere" func="github.com/matrix-org/dendrite/federationsender/consumers.(*OutputEDUConsumer).onTypingEvent" file="github.com/matrix-org/dendrite@/federationsender/consumers/eduserver.go:155" other_server=sw1v.org
time="2020-10-19T17:10:43.566688022Z" level=info msg="Received transaction \"1602838363088\" from \"fs.tum.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=3CzGIzYP6F6P req.method=PUT req.path=/_matrix/federation/v1/send/1602838363088
time="2020-10-19T17:10:43.818963533Z" level=info msg="Received transaction \"1601721138321\" from \"cervoi.se\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=aepbE7tUmGFM req.method=PUT req.path=/_matrix/federation/v1/send/1601721138321
time="2020-10-19T17:10:45.175725829Z" level=info msg="Received transaction \"1602558384947\" from \"matrix.zilroy.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=l97K3V7LQQjR req.method=PUT req.path=/_matrix/federation/v1/send/1602558384947
time="2020-10-19T17:10:45.194962389Z" level=info msg="Received transaction \"1601500823575\" from \"sw1v.org\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=pKguDiI9xFDV req.method=PUT req.path=/_matrix/federation/v1/send/1601500823575
time="2020-10-19T17:10:45.195204912Z" level=info msg="Producing to topic 'DendriteOutputTypingEvent'" func="github.com/matrix-org/dendrite/eduserver/input.(*EDUServerInputAPI).sendTypingEvent" file="github.com/matrix-org/dendrite@/eduserver/input/input.go:104" room_id="!XaqDhxuTIlvldquJaV:matrix.org" typing=false user_id="@richvdh:sw1v.org"
time="2020-10-19T17:10:45.197807948Z" level=info msg="Suppressing typing notif: originated elsewhere" func="github.com/matrix-org/dendrite/federationsender/consumers.(*OutputEDUConsumer).onTypingEvent" file="github.com/matrix-org/dendrite@/federationsender/consumers/eduserver.go:155" other_server=sw1v.org
time="2020-10-19T17:10:45.585565406Z" level=info msg="Received transaction \"1603124344107\" from \"azha.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=kn4hrQTonehJ req.method=PUT req.path=/_matrix/federation/v1/send/1603124344107
time="2020-10-19T17:10:45.601107940Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$60lQbZycG_nDJohKvQz1kXP1kdzOH54BuixyVXN3AEA"
time="2020-10-19T17:10:45.619667012Z" level=info msg="Received transaction \"1601500823632\" from \"sw1v.org\" containing 1 PDUs, 0 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=rNsIxGX91t5J req.method=PUT req.path=/_matrix/federation/v1/send/1601500823632
time="2020-10-19T17:10:45.619858182Z" level=warning msg="Transaction: Failed to query room version for room!XaqDhxuTIlvldquJaV:matrix.org" func="github.com/matrix-org/dendrite/federationapi/routing.(*txnReq).processTransaction" file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:145" error="QueryRoomVersionForRoom: missing room info for room !XaqDhxuTIlvldquJaV:matrix.org" req.id=rNsIxGX91t5J req.method=PUT req.path=/_matrix/federation/v1/send/1601500823632
time="2020-10-19T17:10:45.965290308Z" level=info msg="Received transaction \"1603069266518\" from \"dh9ph.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=7IprGZ27ggt5 req.method=PUT req.path=/_matrix/federation/v1/send/1603069266518
time="2020-10-19T17:10:45.988946729Z" level=info msg="Received transaction \"1603075858866\" from \"pleasecuminside.me\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=h4DAPqZ4UUs7 req.method=PUT req.path=/_matrix/federation/v1/send/1603075858866
time="2020-10-19T17:10:47.816583847Z" level=info msg="Received transaction \"1602350901952\" from \"hackingfor.eu\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=WRTl5U6JURTC req.method=PUT req.path=/_matrix/federation/v1/send/1602350901952
time="2020-10-19T17:10:48.576267565Z" level=info msg="Received transaction \"1602776612272\" from \"maunium.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=XDot5x2Tm6YO req.method=PUT req.path=/_matrix/federation/v1/send/1602776612272
time="2020-10-19T17:10:49.126042971Z" level=info msg="Received transaction \"1603058556657\" from \"freitrix.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=RzLOcvYgtOq3 req.method=PUT req.path=/_matrix/federation/v1/send/1603058556657
time="2020-10-19T17:10:49.532457124Z" level=info msg="Received transaction \"1602779863758\" from \"matrix.blacksec.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=peWC2ozNqJ8R req.method=PUT req.path=/_matrix/federation/v1/send/1602779863758
time="2020-10-19T17:10:50.157760013Z" level=info msg="backfilled 100 events" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).backfillViaFederation" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:119" room_id="!mjbDjyNsRXndKLkHIe:matrix.org"
time="2020-10-19T17:10:50.186450381Z" level=info msg="Received transaction \"1602035698271\" from \"hackeruniverse.dk\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=wm3Q2gjhiPbK req.method=PUT req.path=/_matrix/federation/v1/send/1602035698271
time="2020-10-19T17:10:50.228390828Z" level=info msg="Received transaction \"1602779864188\" from \"matrix.blacksec.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=UkVrUaqP7X3Z req.method=PUT req.path=/_matrix/federation/v1/send/1602779864188
time="2020-10-19T17:10:50.570918761Z" level=info msg="Fetching 17 missing state events (from 5 possible servers)" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:183" context=missing
time="2020-10-19T17:10:50.931333936Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$ZQFLtM4b2ztIiFLUICa0si07AWJ55wiJ9RLrzAwLkX8"
time="2020-10-19T17:10:51.842797818Z" level=info msg="Received transaction \"1601729224545\" from \"matrix.unbl.ink\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=21YPCVUCfFEx req.method=PUT req.path=/_matrix/federation/v1/send/1601729224545
time="2020-10-19T17:10:52.083006321Z" level=info msg="returned 1 PDUs which made events [{Event:0xc00385efa0 Error:<nil> SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$ZQFLtM4b2ztIiFLUICa0si07AWJ55wiJ9RLrzAwLkX8" server=matrix.org
time="2020-10-19T17:10:54.266988359Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$Lde3FQpLYKsBH3CBFYndPOmyP-7Ln7yiKW8cZZvUY_E"
time="2020-10-19T17:10:54.571561518Z" level=info msg="returned 1 PDUs which made events [{Event:0xc001432eb0 Error:<nil> SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$Lde3FQpLYKsBH3CBFYndPOmyP-7Ln7yiKW8cZZvUY_E" server=matrix.org
time="2020-10-19T17:10:55.273785182Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$bCBBU10kZfeEKzFsOaljPYh6r_seFQ9NFs-m1OTerRc"
time="2020-10-19T17:10:55.452237187Z" level=info msg="Received transaction \"1602849981935\" from \"matrix.org\" containing 1 PDUs, 0 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=lnSbm5y9uIMd req.method=PUT req.path=/_matrix/federation/v1/send/1602849981935
time="2020-10-19T17:10:55.453012153Z" level=warning msg="Transaction: Failed to query room version for room!BAXLHOFjvDKUeLafmO:matrix.org" func="github.com/matrix-org/dendrite/federationapi/routing.(*txnReq).processTransaction" file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:145" error="QueryRoomVersionForRoom: missing room info for room !BAXLHOFjvDKUeLafmO:matrix.org" req.id=lnSbm5y9uIMd req.method=PUT req.path=/_matrix/federation/v1/send/1602849981935
time="2020-10-19T17:10:55.772102176Z" level=info msg="Received transaction \"1602849981973\" from \"matrix.org\" containing 1 PDUs, 0 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=cozOaveMsyIW req.method=PUT req.path=/_matrix/federation/v1/send/1602849981973
time="2020-10-19T17:10:55.772397277Z" level=warning msg="Transaction: Failed to query room version for room!BAXLHOFjvDKUeLafmO:matrix.org" func="github.com/matrix-org/dendrite/federationapi/routing.(*txnReq).processTransaction" file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:145" error="QueryRoomVersionForRoom: missing room info for room !BAXLHOFjvDKUeLafmO:matrix.org" req.id=cozOaveMsyIW req.method=PUT req.path=/_matrix/federation/v1/send/1602849981973
time="2020-10-19T17:10:56.676043850Z" level=info msg="Received transaction \"1602849982036\" from \"matrix.org\" containing 1 PDUs, 0 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=NFUoqqAP1ayw req.method=PUT req.path=/_matrix/federation/v1/send/1602849982036
time="2020-10-19T17:10:56.676332422Z" level=warning msg="Transaction: Failed to query room version for room!OGEhHVWSdvArJzumhm:matrix.org" func="github.com/matrix-org/dendrite/federationapi/routing.(*txnReq).processTransaction" file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:145" error="QueryRoomVersionForRoom: missing room info for room !OGEhHVWSdvArJzumhm:matrix.org" req.id=NFUoqqAP1ayw req.method=PUT req.path=/_matrix/federation/v1/send/1602849982036
time="2020-10-19T17:10:58.568721772Z" level=info msg="returned 1 PDUs which made events [{Event:0xc0003f9c20 Error:<nil> SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$bCBBU10kZfeEKzFsOaljPYh6r_seFQ9NFs-m1OTerRc" server=matrix.org
time="2020-10-19T17:10:58.681017696Z" level=info msg="Received transaction \"1597745720545\" from \"entropia.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=Z5toWECrsoSd req.method=PUT req.path=/_matrix/federation/v1/send/1597745720545
time="2020-10-19T17:10:58.789282148Z" level=info msg="Received transaction \"1601297372656\" from \"matrix.vsund.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=VTernON5RnBO req.method=PUT req.path=/_matrix/federation/v1/send/1601297372656
time="2020-10-19T17:10:59.053611554Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$1ifotKVgXpfTdwmPCz0YDayoXRlFQNCYHavLrMZrbbw"
time="2020-10-19T17:10:59.100116182Z" level=info msg="Received transaction \"1600770961778\" from \"riot.firechicken.net\" containing 0 PDUs, 2 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=Fds9DLXXRMuK req.method=PUT req.path=/_matrix/federation/v1/send/1600770961778
time="2020-10-19T17:10:59.522089841Z" level=info msg="Received transaction \"1601513813578\" from \"westwork.org\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=F499vP5cRnY7 req.method=PUT req.path=/_matrix/federation/v1/send/1601513813578
time="2020-10-19T17:10:59.689917905Z" level=info msg="Received transaction \"1597745721854\" from \"entropia.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=vR6AgGIW87DY req.method=PUT req.path=/_matrix/federation/v1/send/1597745721854
time="2020-10-19T17:10:59.750372713Z" level=info msg="Received transaction \"1601297373019\" from \"matrix.vsund.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=78S74OVQDiJe req.method=PUT req.path=/_matrix/federation/v1/send/1601297373019
time="2020-10-19T17:11:00.464159759Z" level=info msg="returned 1 PDUs which made events [{Event:0xc0013c2820 Error:<nil> SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$1ifotKVgXpfTdwmPCz0YDayoXRlFQNCYHavLrMZrbbw" server=matrix.org
time="2020-10-19T17:11:00.605955019Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$OOGTUQwfeOE80A2Z9lW1Jn5T0JwvCmwWEjgWUi7fIhM"
time="2020-10-19T17:11:00.870221015Z" level=info msg="returned 1 PDUs which made events [{Event:0xc0002f83c0 Error:<nil> SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$OOGTUQwfeOE80A2Z9lW1Jn5T0JwvCmwWEjgWUi7fIhM" server=matrix.org
time="2020-10-19T17:11:01.024303345Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$PZwC6tjXcRGWKHMhDAYltHTXzR16IqnliRGouLgPsNY"
time="2020-10-19T17:11:01.306262995Z" level=info msg="Received transaction \"1602849982185\" from \"matrix.org\" containing 1 PDUs, 0 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=9B8hmVTj0Ftu req.method=PUT req.path=/_matrix/federation/v1/send/1602849982185
time="2020-10-19T17:11:01.307080348Z" level=warning msg="Transaction: Failed to query room version for room!UMOdWVcgceMwDXgWtC:matrix.org" func="github.com/matrix-org/dendrite/federationapi/routing.(*txnReq).processTransaction" file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:145" error="QueryRoomVersionForRoom: missing room info for room !UMOdWVcgceMwDXgWtC:matrix.org" req.id=9B8hmVTj0Ftu req.method=PUT req.path=/_matrix/federation/v1/send/1602849982185
time="2020-10-19T17:11:01.550465173Z" level=info msg="Received transaction \"1602587257075\" from \"dataport.modular.im\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=PO4sJxSVky8y req.method=PUT req.path=/_matrix/federation/v1/send/1602587257075
time="2020-10-19T17:11:02.593807245Z" level=info msg="Received transaction \"1602838363700\" from \"fs.tum.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=oKhG9HRbCCxk req.method=PUT req.path=/_matrix/federation/v1/send/1602838363700
time="2020-10-19T17:11:02.769818446Z" level=info msg="Received transaction \"1600770963488\" from \"riot.firechicken.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=8odOvIRylHgJ req.method=PUT req.path=/_matrix/federation/v1/send/1600770963488
time="2020-10-19T17:11:03.419493505Z" level=info msg="Received transaction \"1603076452978\" from \"wvffle.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=FO1ZMWkJdwfw req.method=PUT req.path=/_matrix/federation/v1/send/1603076452978
time="2020-10-19T17:11:03.423194359Z" level=info msg="Received transaction \"1601293745313\" from \"matrix.klass.biz\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=x4MDE90nCQ1b req.method=PUT req.path=/_matrix/federation/v1/send/1601293745313
time="2020-10-19T17:11:05.087888479Z" level=info msg="returned 1 PDUs which made events [{Event:0xc004a938b0 Error:<nil> SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$PZwC6tjXcRGWKHMhDAYltHTXzR16IqnliRGouLgPsNY" server=matrix.org
time="2020-10-19T17:11:05.191343243Z" level=info msg="Received transaction \"1603020288283\" from \"ccc.ac\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=pck4ppuWxbcw req.method=PUT req.path=/_matrix/federation/v1/send/1603020288283
time="2020-10-19T17:11:05.196997345Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$j49V4UL_xkq3yUbDlaLrF6WEiiKP2tFoPvoZbEYU9vM"
time="2020-10-19T17:11:06.168754211Z" level=info msg="returned 1 PDUs which made events [{Event:0xc00084a460 Error:<nil> SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$j49V4UL_xkq3yUbDlaLrF6WEiiKP2tFoPvoZbEYU9vM" server=matrix.org
time="2020-10-19T17:11:06.314605632Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$hiwiQa0H2nH9ilOcymQPXp0uYkQoWW4xzyFbkWwb-fQ"
time="2020-10-19T17:11:06.401930594Z" level=info msg="Received transaction \"1603124822866\" from \"vector.modular.im\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=peaeviPSiQ4G req.method=PUT req.path=/_matrix/federation/v1/send/1603124822866
time="2020-10-19T17:11:06.637365442Z" level=info msg="returned 1 PDUs which made events [{Event:0xc001bf9630 Error:<nil> SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$hiwiQa0H2nH9ilOcymQPXp0uYkQoWW4xzyFbkWwb-fQ" server=matrix.org
time="2020-10-19T17:11:06.990032469Z" level=info msg="Received transaction \"1601297374411\" from \"matrix.vsund.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=C232zCUxUZj0 req.method=PUT req.path=/_matrix/federation/v1/send/1601297374411
time="2020-10-19T17:11:07.475524004Z" level=info msg="Received transaction \"1603110826183\" from \"matrix.dapp.org.uk\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=3zdAVd1PNISI req.method=PUT req.path=/_matrix/federation/v1/send/1603110826183
time="2020-10-19T17:11:07.573140278Z" level=info msg="Received transaction \"1603025370415\" from \"hacklab.fi\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=v4uQMUqdj5o0 req.method=PUT req.path=/_matrix/federation/v1/send/1603025370415
time="2020-10-19T17:11:07.841363650Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$7IMc0cdShxYeBVe-v3TMV7RLk0gDZPWo7C-ezDsuHLg"
time="2020-10-19T17:11:08.098235229Z" level=info msg="returned 1 PDUs which made events [{Event:0xc0012acc80 Error:<nil> SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$7IMc0cdShxYeBVe-v3TMV7RLk0gDZPWo7C-ezDsuHLg" server=matrix.org
time="2020-10-19T17:11:08.227690586Z" level=info msg="Received transaction \"1603025372097\" from \"hacklab.fi\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=YzkQYwnpVDjZ req.method=PUT req.path=/_matrix/federation/v1/send/1603025372097
time="2020-10-19T17:11:08.256804108Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$8b2Jd64WzkTLcNiMF3ReUjnF3fqFS5Clhn8-YQ2DXXU"
time="2020-10-19T17:11:09.361114512Z" level=info msg="Received transaction \"1603020288972\" from \"ccc.ac\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=jvTEYC72C2Tc req.method=PUT req.path=/_matrix/federation/v1/send/1603020288972
time="2020-10-19T17:11:09.576798760Z" level=info msg="Received transaction \"1602021343329\" from \"tlebear.win\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=X8qIyBgWy8a0 req.method=PUT req.path=/_matrix/federation/v1/send/1602021343329
time="2020-10-19T17:11:10.395549403Z" level=info msg="returned 1 PDUs which made events [{Event:0xc001cc82d0 Error:<nil> SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$8b2Jd64WzkTLcNiMF3ReUjnF3fqFS5Clhn8-YQ2DXXU" server=matrix.org
time="2020-10-19T17:11:10.448191808Z" level=info msg="Received transaction \"1603123975207\" from \"finallycoffee.eu\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=c9uTxPGDfGle req.method=PUT req.path=/_matrix/federation/v1/send/1603123975207
time="2020-10-19T17:11:10.546845890Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$XkRGwnLd_KbBKq7-vhKHWOLBiJbhSs8rVmPVuqgFdCw"
time="2020-10-19T17:11:10.582308062Z" level=info msg="Received transaction \"1603124824439\" from \"vector.modular.im\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=G1U1OtFrY52i req.method=PUT req.path=/_matrix/federation/v1/send/1603124824439
time="2020-10-19T17:11:11.336167502Z" level=info msg="returned 1 PDUs which made events [{Event:0xc0022ac280 Error:<nil> SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$XkRGwnLd_KbBKq7-vhKHWOLBiJbhSs8rVmPVuqgFdCw" server=matrix.org
time="2020-10-19T17:11:11.526383350Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$A6ax3p1LbH3Ch93ie6ob2riPqYl0kYgdMM3w7F-SubA"
time="2020-10-19T17:11:12.458034367Z" level=info msg="Received transaction \"1602021345342\" from \"tlebear.win\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=kDDxIJWdakQw req.method=PUT req.path=/_matrix/federation/v1/send/1602021345342
time="2020-10-19T17:11:13.138153105Z" level=info msg="Received transaction \"1603075859451\" from \"pleasecuminside.me\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=HsKo4LL72Xoi req.method=PUT req.path=/_matrix/federation/v1/send/1603075859451
time="2020-10-19T17:11:13.247830150Z" level=info msg="returned 1 PDUs which made events [{Event:0xc0000b0aa0 Error:<nil> SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$A6ax3p1LbH3Ch93ie6ob2riPqYl0kYgdMM3w7F-SubA" server=matrix.org
time="2020-10-19T17:11:13.414785888Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$PrmeW4zyBBCpUODZKdDiJnFLExd-ChC1IXXa5C8bk3A"
time="2020-10-19T17:11:13.984586528Z" level=info msg="Received transaction \"1600770964368\" from \"riot.firechicken.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=7194kUWP5mse req.method=PUT req.path=/_matrix/federation/v1/send/1600770964368
time="2020-10-19T17:11:14.751458290Z" level=info msg="Received transaction \"1600530447526\" from \"chat.dezentrale.space\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=Wn8WS4UT2icV req.method=PUT req.path=/_matrix/federation/v1/send/1600530447526
time="2020-10-19T17:11:14.755718565Z" level=info msg="Received transaction \"1601297375170\" from \"matrix.vsund.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=kMc7xN8HSccL req.method=PUT req.path=/_matrix/federation/v1/send/1601297375170
time="2020-10-19T17:11:15.515561871Z" level=info msg="returned 1 PDUs which made events [{Event:0xc0064065f0 Error:<nil> SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$PrmeW4zyBBCpUODZKdDiJnFLExd-ChC1IXXa5C8bk3A" server=matrix.org
time="2020-10-19T17:11:15.660967309Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$OUVPt67SpDcUoLBDm80HmDGd0kVSkbhpc_5IbRX4KIs"
time="2020-10-19T17:11:16.140789071Z" level=info msg="Received transaction \"1601830682839\" from \"sorunome.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=rYXroMamVsNJ req.method=PUT req.path=/_matrix/federation/v1/send/1601830682839
time="2020-10-19T17:11:16.646237749Z" level=info msg="Received transaction \"1601830686273\" from \"sorunome.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=NzAHLYmkACFG req.method=PUT req.path=/_matrix/federation/v1/send/1601830686273
time="2020-10-19T17:11:16.954344383Z" level=info msg="Received transaction \"1603048961471\" from \"blob.cat\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=qu4ltjPbbajC req.method=PUT req.path=/_matrix/federation/v1/send/1603048961471
time="2020-10-19T17:11:17.015948731Z" level=info msg="returned 1 PDUs which made events [{Event:0xc00109a190 Error:<nil> SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$OUVPt67SpDcUoLBDm80HmDGd0kVSkbhpc_5IbRX4KIs" server=matrix.org
time="2020-10-19T17:11:17.165534260Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$Plq-vR53Vl2f5B-_3rU9OWZq8EAcnY-mB0lqp4oRzQg"
time="2020-10-19T17:11:17.189327928Z" level=info msg="Received transaction \"1600770965147\" from \"riot.firechicken.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=eZY9EzMzN9SP req.method=PUT req.path=/_matrix/federation/v1/send/1600770965147
time="2020-10-19T17:11:17.473592125Z" level=info msg="Received transaction \"1603124825502\" from \"vector.modular.im\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=nhKuBrnmgVUZ req.method=PUT req.path=/_matrix/federation/v1/send/1603124825502
time="2020-10-19T17:11:17.557285924Z" level=info msg="Received transaction \"1601897927253\" from \"dewith.io\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=Tv3A0Wh3pea8 req.method=PUT req.path=/_matrix/federation/v1/send/1601897927253
time="2020-10-19T17:11:17.668398402Z" level=info msg="Received transaction \"1602667906800\" from \"taboulisme.com\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=HaHzen7RJlww req.method=PUT req.path=/_matrix/federation/v1/send/1602667906800
time="2020-10-19T17:11:17.803437457Z" level=info msg="Received transaction \"1602178318909\" from \"matrix.kraut.space\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=qYijTtyLkEsR req.method=PUT req.path=/_matrix/federation/v1/send/1602178318909
time="2020-10-19T17:11:18.120302942Z" level=info msg="Received transaction \"1602881163642\" from \"kif.rocks\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=4HeKFgjYbVMw req.method=PUT req.path=/_matrix/federation/v1/send/1602881163642
time="2020-10-19T17:11:18.243699832Z" level=info msg="returned 1 PDUs which made events [{Event:0xc009d003c0 Error:<nil> SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$Plq-vR53Vl2f5B-_3rU9OWZq8EAcnY-mB0lqp4oRzQg" server=matrix.org
time="2020-10-19T17:11:18.387443211Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$Kphn2lnj40eyZcZhMs65HJUabB2f2dtKzgjFqjgSY0g"
time="2020-10-19T17:11:18.735911506Z" level=info msg="Received transaction \"1602881164648\" from \"kif.rocks\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=CgTlaq9m2ecO req.method=PUT req.path=/_matrix/federation/v1/send/1602881164648
time="2020-10-19T17:11:19.250374271Z" level=info msg="Received transaction \"1603067959285\" from \"targodan.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=t7bL4UpIjM4U req.method=PUT req.path=/_matrix/federation/v1/send/1603067959285
time="2020-10-19T17:11:19.648673150Z" level=info msg="returned 1 PDUs which made events [{Event:0xc0046336d0 Error:<nil> SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$Kphn2lnj40eyZcZhMs65HJUabB2f2dtKzgjFqjgSY0g" server=matrix.org
time="2020-10-19T17:11:19.816216883Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$4PJ559JARX96wJWpHWH39uQIz20hQYJI67cAEadJX7o"
time="2020-10-19T17:11:20.302814497Z" level=info msg="Received transaction \"1603074972374\" from \"glbrown.org\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=bVRs11qRSV6q req.method=PUT req.path=/_matrix/federation/v1/send/1603074972374
time="2020-10-19T17:11:20.575605022Z" level=info msg="Received transaction \"1600770965559\" from \"riot.firechicken.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=Smdcp9KGXGEp req.method=PUT req.path=/_matrix/federation/v1/send/1600770965559
time="2020-10-19T17:11:21.476414661Z" level=info msg="returned 1 PDUs which made events [{Event:0xc009d01860 Error:<nil> SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$4PJ559JARX96wJWpHWH39uQIz20hQYJI67cAEadJX7o" server=matrix.org
time="2020-10-19T17:11:21.476507695Z" level=info msg="Persisting 17 new events" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:220" context=missing
time="2020-10-19T17:11:21.756800750Z" level=info msg="Received transaction \"1603124827082\" from \"vector.modular.im\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=ABergFyznfWq req.method=PUT req.path=/_matrix/federation/v1/send/1603124827082
time="2020-10-19T17:11:22.591748723Z" level=info msg="Received transaction \"1600770966278\" from \"riot.firechicken.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=jWI7e0juznGd req.method=PUT req.path=/_matrix/federation/v1/send/1600770966278
time="2020-10-19T17:11:23.701718401Z" level=info msg="Received transaction \"1602035698884\" from \"hackeruniverse.dk\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=cRMI5rXlkjUi req.method=PUT req.path=/_matrix/federation/v1/send/1602035698884
time="2020-10-19T17:11:23.978299164Z" level=info msg="Received transaction \"1603074025845\" from \"matrix.vgorcum.com\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=z3maUPYkNcec req.method=PUT req.path=/_matrix/federation/v1/send/1603074025845
time="2020-10-19T17:11:24.176501875Z" level=info msg="Received transaction \"1600267508557\" from \"aeum.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=s17PzE2P8KmP req.method=PUT req.path=/_matrix/federation/v1/send/1600267508557
time="2020-10-19T17:11:24.473827169Z" level=info msg="Received transaction \"1603039805711\" from \"hemmerle.dev\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=5KLryVRskJwJ req.method=PUT req.path=/_matrix/federation/v1/send/1603039805711
time="2020-10-19T17:11:26.677443175Z" level=info msg="Received transaction \"1600603994309\" from \"samcday.com\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=v3b5zAIWOrnj req.method=PUT req.path=/_matrix/federation/v1/send/1600603994309
time="2020-10-19T17:11:29.584531113Z" level=info msg="Received transaction \"1603058556752\" from \"freitrix.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=NYDIAjEoiG99 req.method=PUT req.path=/_matrix/federation/v1/send/1603058556752
time="2020-10-19T17:11:30.091961760Z" level=info msg="Received transaction \"1602931987543\" from \"matrix.fff.community\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=ar4fvdxnZV8j req.method=PUT req.path=/_matrix/federation/v1/send/1602931987543
time="2020-10-19T17:11:30.569746504Z" level=info msg="Received transaction \"1603015054346\" from \"mgottschlag.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=eHaiMD7fTNJM req.method=PUT req.path=/_matrix/federation/v1/send/1603015054346
time="2020-10-19T17:11:30.760635722Z" level=info msg="Received transaction \"1600770966795\" from \"riot.firechicken.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=ZzM58GiuaaHj req.method=PUT req.path=/_matrix/federation/v1/send/1600770966795
time="2020-10-19T17:11:30.853852858Z" level=info msg="Received transaction \"1602773982967\" from \"eisfunke.com\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=P9BJdSEz1Zku req.method=PUT req.path=/_matrix/federation/v1/send/1602773982967
time="2020-10-19T17:11:30.879488259Z" level=info msg="Received transaction \"1602773983893\" from \"eisfunke.com\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=FycjwuPmdhwM req.method=PUT req.path=/_matrix/federation/v1/send/1602773983893
time="2020-10-19T17:11:31.885592471Z" level=info msg="Received transaction \"1601688857518\" from \"antonok.com\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=JNBTAVGHhhza req.method=PUT req.path=/_matrix/federation/v1/send/1601688857518
time="2020-10-19T17:11:32.401652138Z" level=info msg="Fetching 2 missing state events (from 5 possible servers)" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:183" context=missing
time="2020-10-19T17:11:32.590940998Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$Cy422JWZfhqceNdYVujlCYCWWA5KZNl3bjUGTqO23-E"
time="2020-10-19T17:11:32.690389248Z" level=info msg="Received transaction \"1603048962163\" from \"blob.cat\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=3I0u3F2g7Z5Y req.method=PUT req.path=/_matrix/federation/v1/send/1603048962163
time="2020-10-19T17:11:33.559309295Z" level=info msg="Received transaction \"1600770967557\" from \"riot.firechicken.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=BXDHCOD3TO3S req.method=PUT req.path=/_matrix/federation/v1/send/1600770967557
time="2020-10-19T17:11:33.982865081Z" level=info msg="returned 1 PDUs which made events [{Event:0xc00a3828c0 Error:<nil> SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$Cy422JWZfhqceNdYVujlCYCWWA5KZNl3bjUGTqO23-E" server=matrix.org
time="2020-10-19T17:11:34.140054921Z" level=info msg="Requesting /state_ids at event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).StateIDsBeforeEvent" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:290" event_id="$V6eeJTkHpamYcr_WC_9_iEr01CcNEwHTqo_oFIPfr7k"
time="2020-10-19T17:11:34.540398695Z" level=info msg="returned 1 PDUs which made events [{Event:0xc0012ac280 Error:<nil> SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$V6eeJTkHpamYcr_WC_9_iEr01CcNEwHTqo_oFIPfr7k" server=matrix.org
time="2020-10-19T17:11:34.540572154Z" level=info msg="Persisting 2 new events" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:220" context=missing
time="2020-10-19T17:11:34.886864128Z" level=info msg="Received transaction \"1601293745678\" from \"matrix.klass.biz\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=xVo1NuoYiwQ6 req.method=PUT req.path=/_matrix/federation/v1/send/1601293745678
time="2020-10-19T17:11:35.065184932Z" level=info msg="Received transaction \"1600974925391\" from \"parlante.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=AqAKuZfE9yDw req.method=PUT req.path=/_matrix/federation/v1/send/1600974925391
time="2020-10-19T17:11:35.349683183Z" level=info msg="Received transaction \"1602838364400\" from \"fs.tum.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=cGJmdsHkgFRG req.method=PUT req.path=/_matrix/federation/v1/send/1602838364400
time="2020-10-19T17:11:38.501071400Z" level=info msg="Received transaction \"1602704322662\" from \"dho.se\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=btLxALRJg0ho req.method=PUT req.path=/_matrix/federation/v1/send/1602704322662
time="2020-10-19T17:11:38.751343498Z" level=info msg="Received transaction \"1602778317182\" from \"flobob.ovh\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=ncEh7oQU4j54 req.method=PUT req.path=/_matrix/federation/v1/send/1602778317182
time="2020-10-19T17:11:39.248945752Z" level=info msg="Received transaction \"1602779776611\" from \"hnitbjorg.xyz\" containing 0 PDUs, 2 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=2dIhecTCxLYO req.method=PUT req.path=/_matrix/federation/v1/send/1602779776611
time="2020-10-19T17:11:39.326705295Z" level=info msg="Received transaction \"1602772699317\" from \"half-shot.uk\" containing 0 PDUs, 2 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=YcCZPBh4j2zB req.method=PUT req.path=/_matrix/federation/v1/send/1602772699317
time="2020-10-19T17:11:39.326903324Z" level=info msg="Producing to topic 'DendriteOutputTypingEvent'" func="github.com/matrix-org/dendrite/eduserver/input.(*EDUServerInputAPI).sendTypingEvent" file="github.com/matrix-org/dendrite@/eduserver/input/input.go:104" room_id="!XaqDhxuTIlvldquJaV:matrix.org" typing=true user_id="@Half-Shot:half-shot.uk"
time="2020-10-19T17:11:39.330226239Z" level=info msg="Suppressing typing notif: originated elsewhere" func="github.com/matrix-org/dendrite/federationsender/consumers.(*OutputEDUConsumer).onTypingEvent" file="github.com/matrix-org/dendrite@/federationsender/consumers/eduserver.go:155" other_server=half-shot.uk
time="2020-10-19T17:11:40.237414525Z" level=info msg="Received transaction \"1602778318858\" from \"flobob.ovh\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=k3hllAoGRwyI req.method=PUT req.path=/_matrix/federation/v1/send/1602778318858
time="2020-10-19T17:11:40.520440942Z" level=info msg="Received transaction \"1602779777595\" from \"hnitbjorg.xyz\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=LmaV8oR3BmtJ req.method=PUT req.path=/_matrix/federation/v1/send/1602779777595
time="2020-10-19T17:11:40.650702139Z" level=info msg="Received transaction \"1603045750086\" from \"elsmussols.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=kgLBC7UIMeUi req.method=PUT req.path=/_matrix/federation/v1/send/1603045750086
time="2020-10-19T17:11:42.760979980Z" level=info msg="Received transaction \"1603045750835\" from \"elsmussols.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=PPIiRnpixumL req.method=PUT req.path=/_matrix/federation/v1/send/1603045750835
time="2020-10-19T17:11:43.221564842Z" level=info msg="Received transaction \"1603074760083\" from \"matrix.geklautecloud.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=IEeDYYFxzgjZ req.method=PUT req.path=/_matrix/federation/v1/send/1603074760083
time="2020-10-19T17:11:46.853471205Z" level=info msg="Received transaction \"1602849982805\" from \"matrix.org\" containing 1 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=gt4Jzhurz55g req.method=PUT req.path=/_matrix/federation/v1/send/1602849982805
time="2020-10-19T17:11:46.865202804Z" level=warning msg="Transaction: Failed to query room version for room!OGEhHVWSdvArJzumhm:matrix.org" func="github.com/matrix-org/dendrite/federationapi/routing.(*txnReq).processTransaction" file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:145" error="QueryRoomVersionForRoom: missing room info for room !OGEhHVWSdvArJzumhm:matrix.org" req.id=gt4Jzhurz55g req.method=PUT req.path=/_matrix/federation/v1/send/1602849982805
time="2020-10-19T17:11:47.508326683Z" level=info msg="Received transaction \"1602849982927\" from \"matrix.org\" containing 1 PDUs, 0 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=Dg2ORPNlzoFx req.method=PUT req.path=/_matrix/federation/v1/send/1602849982927
time="2020-10-19T17:11:47.509207790Z" level=warning msg="Transaction: Failed to query room version for room!OGEhHVWSdvArJzumhm:matrix.org" func="github.com/matrix-org/dendrite/federationapi/routing.(*txnReq).processTransaction" file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:145" error="QueryRoomVersionForRoom: missing room info for room !OGEhHVWSdvArJzumhm:matrix.org" req.id=Dg2ORPNlzoFx req.method=PUT req.path=/_matrix/federation/v1/send/1602849982927
time="2020-10-19T17:11:48.093868746Z" level=info msg="Received transaction \"1603047229767\" from \"locadmin.nl\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=BFIgMa6Lyc14 req.method=PUT req.path=/_matrix/federation/v1/send/1603047229767
time="2020-10-19T17:11:48.190373622Z" level=info msg="Received transaction \"1602849983069\" from \"matrix.org\" containing 1 PDUs, 0 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=rUdw082R72EW req.method=PUT req.path=/_matrix/federation/v1/send/1602849983069
time="2020-10-19T17:11:48.191230773Z" level=warning msg="Transaction: Failed to query room version for room!OGEhHVWSdvArJzumhm:matrix.org" func="github.com/matrix-org/dendrite/federationapi/routing.(*txnReq).processTransaction" file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:145" error="QueryRoomVersionForRoom: missing room info for room !OGEhHVWSdvArJzumhm:matrix.org" req.id=rUdw082R72EW req.method=PUT req.path=/_matrix/federation/v1/send/1602849983069
time="2020-10-19T17:11:48.956812965Z" level=info msg="Received transaction \"1602772699410\" from \"half-shot.uk\" containing 0 PDUs, 2 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=TU72cOZAZ1Bj req.method=PUT req.path=/_matrix/federation/v1/send/1602772699410
time="2020-10-19T17:11:48.956942886Z" level=info msg="Producing to topic 'DendriteOutputTypingEvent'" func="github.com/matrix-org/dendrite/eduserver/input.(*EDUServerInputAPI).sendTypingEvent" file="github.com/matrix-org/dendrite@/eduserver/input/input.go:104" room_id="!XaqDhxuTIlvldquJaV:matrix.org" typing=false user_id="@Half-Shot:half-shot.uk"
time="2020-10-19T17:11:48.958753473Z" level=info msg="Suppressing typing notif: originated elsewhere" func="github.com/matrix-org/dendrite/federationsender/consumers.(*OutputEDUConsumer).onTypingEvent" file="github.com/matrix-org/dendrite@/federationsender/consumers/eduserver.go:155" other_server=half-shot.uk
time="2020-10-19T17:11:48.983160487Z" level=info msg="Received transaction \"1602772699492\" from \"half-shot.uk\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=042sZWzSetjl req.method=PUT req.path=/_matrix/federation/v1/send/1602772699492
time="2020-10-19T17:11:48.983300515Z" level=info msg="Producing to topic 'DendriteOutputTypingEvent'" func="github.com/matrix-org/dendrite/eduserver/input.(*EDUServerInputAPI).sendTypingEvent" file="github.com/matrix-org/dendrite@/eduserver/input/input.go:104" room_id="!XaqDhxuTIlvldquJaV:matrix.org" typing=true user_id="@Half-Shot:half-shot.uk"
time="2020-10-19T17:11:48.985431167Z" level=info msg="Suppressing typing notif: originated elsewhere" func="github.com/matrix-org/dendrite/federationsender/consumers.(*OutputEDUConsumer).onTypingEvent" file="github.com/matrix-org/dendrite@/federationsender/consumers/eduserver.go:155" other_server=half-shot.uk
time="2020-10-19T17:11:49.676737598Z" level=info msg="Received transaction \"1603058556843\" from \"freitrix.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=llMBYmSSpNpb req.method=PUT req.path=/_matrix/federation/v1/send/1603058556843
time="2020-10-19T17:11:50.077823140Z" level=info msg="Received transaction \"1603049164607\" from \"matrix.exceptionerror.io\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=nXpLMgHHiSf9 req.method=PUT req.path=/_matrix/federation/v1/send/1603049164607
time="2020-10-19T17:11:50.212718985Z" level=info msg="Received transaction \"1602584798453\" from \"the.m4tr1x.chat\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=y8e5C6MJ1kcR req.method=PUT req.path=/_matrix/federation/v1/send/1602584798453
time="2020-10-19T17:11:50.840917789Z" level=info msg="Received transaction \"1602440994607\" from \"brixit.nl\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=yRdQGxsoD56M req.method=PUT req.path=/_matrix/federation/v1/send/1602440994607
time="2020-10-19T17:11:51.068576808Z" level=info msg="Received transaction \"1603123977189\" from \"finallycoffee.eu\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=ajX7ti4btA0t req.method=PUT req.path=/_matrix/federation/v1/send/1603123977189
time="2020-10-19T17:11:51.071590078Z" level=info msg="Received transaction \"1602440996083\" from \"brixit.nl\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=b7Ib4Ol5hDYs req.method=PUT req.path=/_matrix/federation/v1/send/1602440996083
time="2020-10-19T17:11:53.086907270Z" level=info msg="Received transaction \"1602035699495\" from \"hackeruniverse.dk\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=0QOah1pHUWZ3 req.method=PUT req.path=/_matrix/federation/v1/send/1602035699495
time="2020-10-19T17:11:54.718649327Z" level=info msg="Received transaction \"1603049229075\" from \"luca0n.com\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=GYsoWtkpJtTy req.method=PUT req.path=/_matrix/federation/v1/send/1603049229075
time="2020-10-19T17:11:55.015605731Z" level=info msg="Received transaction \"1602838310534\" from \"imbitbu.de\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=J9Y2uDtF1BUV req.method=PUT req.path=/_matrix/federation/v1/send/1602838310534
time="2020-10-19T17:11:55.475468797Z" level=info msg="Received transaction \"1600579914665\" from \"matrix.2xl.su\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=mCtFsyzUkc3S req.method=PUT req.path=/_matrix/federation/v1/send/1600579914665
time="2020-10-19T17:11:57.225836556Z" level=info msg="Received transaction \"1602521693328\" from \"kolosowscy.pl\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=Dw3Tqm7GazEh req.method=PUT req.path=/_matrix/federation/v1/send/1602521693328
time="2020-10-19T17:11:57.471724093Z" level=info msg="Received transaction \"1602778552314\" from \"ctrl-c.liu.se\" containing 0 PDUs, 2 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=Ju3fNDFpCbHy req.method=PUT req.path=/_matrix/federation/v1/send/1602778552314
time="2020-10-19T17:11:57.471934353Z" level=info msg="Producing to topic 'DendriteOutputTypingEvent'" func="github.com/matrix-org/dendrite/eduserver/input.(*EDUServerInputAPI).sendTypingEvent" file="github.com/matrix-org/dendrite@/eduserver/input/input.go:104" room_id="!xYvNcQPhnkrdUmYczI:matrix.org" typing=true user_id="@magnus:ctrl-c.liu.se"
time="2020-10-19T17:11:57.474193882Z" level=info msg="Suppressing typing notif: originated elsewhere" func="github.com/matrix-org/dendrite/federationsender/consumers.(*OutputEDUConsumer).onTypingEvent" file="github.com/matrix-org/dendrite@/federationsender/consumers/eduserver.go:155" other_server=ctrl-c.liu.se
time="2020-10-19T17:11:58.211255378Z" level=info msg="Received transaction \"1602875911733\" from \"envs.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=lVLCySWQbFae req.method=PUT req.path=/_matrix/federation/v1/send/1602875911733
time="2020-10-19T17:11:58.796424436Z" level=info msg="Received transaction \"1602875912518\" from \"envs.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=FHRrhWrzX7bV req.method=PUT req.path=/_matrix/federation/v1/send/1602875912518
time="2020-10-19T17:11:59.153026268Z" level=info msg="Received transaction \"1602772699600\" from \"half-shot.uk\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=n1PlwZFEyomV req.method=PUT req.path=/_matrix/federation/v1/send/1602772699600
time="2020-10-19T17:11:59.153220688Z" level=info msg="Producing to topic 'DendriteOutputTypingEvent'" func="github.com/matrix-org/dendrite/eduserver/input.(*EDUServerInputAPI).sendTypingEvent" file="github.com/matrix-org/dendrite@/eduserver/input/input.go:104" room_id="!XaqDhxuTIlvldquJaV:matrix.org" typing=false user_id="@Half-Shot:half-shot.uk"
time="2020-10-19T17:11:59.155471891Z" level=info msg="Suppressing typing notif: originated elsewhere" func="github.com/matrix-org/dendrite/federationsender/consumers.(*OutputEDUConsumer).onTypingEvent" file="github.com/matrix-org/dendrite@/federationsender/consumers/eduserver.go:155" other_server=half-shot.uk
time="2020-10-19T17:12:00.396492553Z" level=info msg="Received transaction \"1602772699695\" from \"half-shot.uk\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=D4TrN9zaqFxH req.method=PUT req.path=/_matrix/federation/v1/send/1602772699695
time="2020-10-19T17:12:00.396691663Z" level=info msg="Producing to topic 'DendriteOutputTypingEvent'" func="github.com/matrix-org/dendrite/eduserver/input.(*EDUServerInputAPI).sendTypingEvent" file="github.com/matrix-org/dendrite@/eduserver/input/input.go:104" room_id="!XaqDhxuTIlvldquJaV:matrix.org" typing=true user_id="@Half-Shot:half-shot.uk"
time="2020-10-19T17:12:00.399603470Z" level=info msg="Suppressing typing notif: originated elsewhere" func="github.com/matrix-org/dendrite/federationsender/consumers.(*OutputEDUConsumer).onTypingEvent" file="github.com/matrix-org/dendrite@/federationsender/consumers/eduserver.go:155" other_server=half-shot.uk
time="2020-10-19T17:12:00.529286468Z" level=info msg="Received transaction \"1603115232939\" from \"luschmar.ch\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=OX4btEOu2hCA req.method=PUT req.path=/_matrix/federation/v1/send/1603115232939
time="2020-10-19T17:12:00.574278198Z" level=info msg="Received transaction \"1602682116131\" from \"hackerfleet.eu\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=cTJZJBpSD84n req.method=PUT req.path=/_matrix/federation/v1/send/1602682116131
time="2020-10-19T17:12:00.635129923Z" level=info msg="Received transaction \"1602849983400\" from \"matrix.org\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=l7dlYfPR5nr5 req.method=PUT req.path=/_matrix/federation/v1/send/1602849983400
time="2020-10-19T17:12:00.653266151Z" level=info msg="Received transaction \"1603114825622\" from \"matrix.x51.pl\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=wCtZWIFdqAbB req.method=PUT req.path=/_matrix/federation/v1/send/1603114825622
time="2020-10-19T17:12:01.403680951Z" level=info msg="Received transaction \"1603070049942\" from \"tilde.fun\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=Pak7UZT0kF3t req.method=PUT req.path=/_matrix/federation/v1/send/1603070049942
time="2020-10-19T17:12:01.978070316Z" level=info msg="Received transaction \"1603070050808\" from \"tilde.fun\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=T2EVh5atFIJG req.method=PUT req.path=/_matrix/federation/v1/send/1603070050808
time="2020-10-19T17:12:02.741611264Z" level=info msg="Received transaction \"1602589831571\" from \"siika.solutions\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=CcypWkULNOsQ req.method=PUT req.path=/_matrix/federation/v1/send/1602589831571
time="2020-10-19T17:12:04.558912545Z" level=info msg="Received transaction \"1602778552573\" from \"ctrl-c.liu.se\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=ucTd6hRE1KSL req.method=PUT req.path=/_matrix/federation/v1/send/1602778552573
time="2020-10-19T17:12:04.558960324Z" level=info msg="Producing to topic 'DendriteOutputTypingEvent'" func="github.com/matrix-org/dendrite/eduserver/input.(*EDUServerInputAPI).sendTypingEvent" file="github.com/matrix-org/dendrite@/eduserver/input/input.go:104" room_id="!xYvNcQPhnkrdUmYczI:matrix.org" typing=false user_id="@magnus:ctrl-c.liu.se"
time="2020-10-19T17:12:04.559985583Z" level=info msg="Suppressing typing notif: originated elsewhere" func="github.com/matrix-org/dendrite/federationsender/consumers.(*OutputEDUConsumer).onTypingEvent" file="github.com/matrix-org/dendrite@/federationsender/consumers/eduserver.go:155" other_server=ctrl-c.liu.se
time="2020-10-19T17:12:05.022006288Z" level=info msg="Fetching 1 missing state events (from 5 possible servers)" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:183" context=missing
time="2020-10-19T17:12:05.117391842Z" level=info msg="returned 1 PDUs which made events [{Event:<nil> Error:Bad signature from \"matrix.org\" with ID \"ed25519:auto\" SoftFail:false}]" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:203" context=missing event_id="$zTjQbxV26Zs_Jan_Km9kbq7YScafrGYhYMT0rKtJP7o" server=matrix.org
time="2020-10-19T17:12:05.117457213Z" level=warning msg="event failed PDU checks" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:206" context=missing error="Bad signature from \"matrix.org\" with ID \"ed25519:auto\"" event_id="$zTjQbxV26Zs_Jan_Km9kbq7YScafrGYhYMT0rKtJP7o" server=matrix.org
time="2020-10-19T17:12:05.710293923Z" level=warning msg="failed to get event from server" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:194" context=missing error="contents=[34 34] msg=Failed to GET JSON (hostname \"matrix.batna.ir\" path \"/_matrix/federation/v1/event/$zTjQbxV26Zs_Jan_Km9kbq7YScafrGYhYMT0rKtJP7o\"): \"\" code=404 wrapped= - (retry_after=0s, blacklisted=false)" event_id="$zTjQbxV26Zs_Jan_Km9kbq7YScafrGYhYMT0rKtJP7o" server=matrix.batna.ir
time="2020-10-19T17:12:06.863519975Z" level=warning msg="failed to get event from server" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:194" context=missing error="contents=[34 34] msg=Failed to GET JSON (hostname \"matrix.decibite.com\" path \"/_matrix/federation/v1/event/$zTjQbxV26Zs_Jan_Km9kbq7YScafrGYhYMT0rKtJP7o\"): \"\" code=404 wrapped= - (retry_after=0s, blacklisted=false)" event_id="$zTjQbxV26Zs_Jan_Km9kbq7YScafrGYhYMT0rKtJP7o" server=matrix.decibite.com
time="2020-10-19T17:12:07.006795777Z" level=warning msg="failed to get event from server" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:194" context=missing error="contents=[34 34] msg=Failed to GET JSON (hostname \"ralith.com\" path \"/_matrix/federation/v1/event/$zTjQbxV26Zs_Jan_Km9kbq7YScafrGYhYMT0rKtJP7o\"): \"\" code=404 wrapped= - (retry_after=0s, blacklisted=false)" event_id="$zTjQbxV26Zs_Jan_Km9kbq7YScafrGYhYMT0rKtJP7o" server=ralith.com
time="2020-10-19T17:12:07.028309066Z" level=info msg="Received transaction \"1603116786910\" from \"kusoneko.moe\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=om8MZOHlsUfI req.method=PUT req.path=/_matrix/federation/v1/send/1603116786910
time="2020-10-19T17:12:07.831151375Z" level=info msg="Received transaction \"1602552679371\" from \"shivering-isles.com\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=CktsXl8fpCs2 req.method=PUT req.path=/_matrix/federation/v1/send/1602552679371
time="2020-10-19T17:12:08.461966749Z" level=info msg="Received transaction \"1602982670067\" from \"bsv.direct\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=5dtMEAhT8eVD req.method=PUT req.path=/_matrix/federation/v1/send/1602982670067
time="2020-10-19T17:12:08.701406871Z" level=info msg="Received transaction \"1603045752540\" from \"elsmussols.net\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=VLosbwIV4oHw req.method=PUT req.path=/_matrix/federation/v1/send/1603045752540
time="2020-10-19T17:12:09.192369109Z" level=info msg="Received transaction \"1602795736208\" from \"ubbink.org\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=duNx3b5elHaB req.method=PUT req.path=/_matrix/federation/v1/send/1602795736208
time="2020-10-19T17:12:09.324216332Z" level=info msg="Received transaction \"1603048962999\" from \"blob.cat\" containing 0 PDUs, 1 EDUs" func=github.com/matrix-org/dendrite/federationapi/routing.Send file="github.com/matrix-org/dendrite@/federationapi/routing/send.go:85" req.id=2r3qNTslaeiG req.method=PUT req.path=/_matrix/federation/v1/send/1603048962999
time="2020-10-19T17:12:09.432965762Z" level=warning msg="failed to get event from server" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:194" context=missing error="contents=[34 34] msg=Failed to GET JSON (hostname \"synapse.travnewmatic.com\" path \"/_matrix/federation/v1/event/$zTjQbxV26Zs_Jan_Km9kbq7YScafrGYhYMT0rKtJP7o\"): \"\" code=404 wrapped= - (retry_after=0s, blacklisted=false)" event_id="$zTjQbxV26Zs_Jan_Km9kbq7YScafrGYhYMT0rKtJP7o" server=synapse.travnewmatic.com
time="2020-10-19T17:12:09.433145658Z" level=info msg="Persisting 0 new events" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).fetchAndStoreMissingEvents" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:220" context=missing
time="2020-10-19T17:12:09.490912906Z" level=error msg="backfillViaFederation: failed to get state entries for event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).backfillViaFederation" file="github.com/matrix-org/dendrite@/roomserver/internal/perform/perform_backfill.go:143" error="storage: state event IDs missing from the database (8968 != 8969)" event_id="$2AI8r-den3CPVvVDOCgnptW6KPhX_XAObCAatByokmI"
time="2020-10-19T17:12:09.490972549Z" level=error msg="mreq.retrieveEvents failed" func=github.com/matrix-org/dendrite/syncapi/routing.OnIncomingMessagesRequest file="github.com/matrix-org/dendrite@/syncapi/routing/messages.go:161" error="PerformBackfill failed: storage: state event IDs missing from the database (8968 != 8969)" req.id=9bhlHdScHKhw req.method=GET req.path="/_matrix/client/r0/rooms/!mjbDjyNsRXndKLkHIe:matrix.org/messages" user_id="@pestdoktor:fentker.eu"

Oct 19 '20 17:10 Pestdoktor

The actual relevant error here is storage: state event IDs missing from the database (8968 != 8969).

Oct 19 '20 17:10 neilalexander

Not seeing this anymore (possibly because of updating to v0.20.1?)

time="2020-10-23T14:10:39.413898458Z" level=info msg="Fetched 100 events locally" func="github.com/matrix-org/dendrite/syncapi/routing.(*messagesReq).retrieveEvents" file="github.com/matrix-org/dendrite/syncapi/routing/messages.go:212" end="{{ []}}" req.id=2JAgj4rIfgh1 req.method=GET req.path="/_matrix/client/r0/rooms/!mjbDjyNsRXndKLkHIe:matrix.org/messages" start="{{ []}}" user_id="@pestdoktor:fentker.eu"
time="2020-10-23T14:10:39.414665863Z" level=error msg="QueryStateAfterEvents: MissingEventError: storage: missing state for event NID 226996" func="github.com/matrix-org/dendrite/roomserver/internal/query.(*Queryer).QueryStateAfterEvents" file="github.com/matrix-org/dendrite/roomserver/internal/query/query.go:74" req.id=2JAgj4rIfgh1 req.method=GET req.path="/_matrix/client/r0/rooms/!mjbDjyNsRXndKLkHIe:matrix.org/messages" user_id="@pestdoktor:fentker.eu"
time="2020-10-23T14:10:39.415042612Z" level=info msg=Responding func=github.com/matrix-org/dendrite/syncapi/routing.OnIncomingMessagesRequest file="github.com/matrix-org/dendrite/syncapi/routing/messages.go:172" backwards=true from=t150314_31863 limit=100 req.id=2JAgj4rIfgh1 req.method=GET req.path="/_matrix/client/r0/rooms/!mjbDjyNsRXndKLkHIe:matrix.org/messages" return_end=t149492_31679 return_start=t150314_30689 to=t0_0 user_id="@pestdoktor:fentker.eu"
time="2020-10-23T14:10:39.539371895Z" level=info msg="Fetched 23 events locally" func="github.com/matrix-org/dendrite/syncapi/routing.(*messagesReq).retrieveEvents" file="github.com/matrix-org/dendrite/syncapi/routing/messages.go:212" end="{{ []}}" req.id=U9QxxK60Pkif req.method=GET req.path="/_matrix/client/r0/rooms/!mjbDjyNsRXndKLkHIe:matrix.org/messages" start="{{ []}}" user_id="@pestdoktor:fentker.eu"
time="2020-10-23T14:10:39.540540720Z" level=error msg="ServersAtEvent: failed to load state before event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).ServersAtEvent" file="github.com/matrix-org/dendrite/roomserver/internal/perform/perform_backfill.go:424" error="storage: missing state for event NID 227185" event_id="$iQG_pXDDalysua3b25-R1yjwVLbSDLRG1_iURva7XbA"
time="2020-10-23T14:10:39.540575461Z" level=info msg="backfilled 0 events" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).backfillViaFederation" file="github.com/matrix-org/dendrite/roomserver/internal/perform/perform_backfill.go:119" room_id="!mjbDjyNsRXndKLkHIe:matrix.org"
time="2020-10-23T14:10:39.540616966Z" level=info msg="Storing new events from backfill" func="github.com/matrix-org/dendrite/syncapi/routing.(*messagesReq).backfill" file="github.com/matrix-org/dendrite/syncapi/routing/messages.go:490" new_events=0 req.id=U9QxxK60Pkif req.method=GET req.path="/_matrix/client/r0/rooms/!mjbDjyNsRXndKLkHIe:matrix.org/messages" user_id="@pestdoktor:fentker.eu"
time="2020-10-23T14:10:39.542761500Z" level=error msg="QueryStateAfterEvents: MissingEventError: storage: missing state for event NID 212179" func="github.com/matrix-org/dendrite/roomserver/internal/query.(*Queryer).QueryStateAfterEvents" file="github.com/matrix-org/dendrite/roomserver/internal/query/query.go:74" req.id=U9QxxK60Pkif req.method=GET req.path="/_matrix/client/r0/rooms/!mjbDjyNsRXndKLkHIe:matrix.org/messages" user_id="@pestdoktor:fentker.eu"
time="2020-10-23T14:10:39.543143617Z" level=info msg=Responding func=github.com/matrix-org/dendrite/syncapi/routing.OnIncomingMessagesRequest file="github.com/matrix-org/dendrite/syncapi/routing/messages.go:172" backwards=true from=t149492_31679 limit=100 req.id=U9QxxK60Pkif req.method=GET req.path="/_matrix/client/r0/rooms/!mjbDjyNsRXndKLkHIe:matrix.org/messages" return_end=t138349_35889 return_start=t149484_30680 to=t0_0 user_id="@pestdoktor:fentker.eu"
time="2020-10-23T14:10:39.665586752Z" level=info msg="Fetched 0 events locally" func="github.com/matrix-org/dendrite/syncapi/routing.(*messagesReq).retrieveEvents" file="github.com/matrix-org/dendrite/syncapi/routing/messages.go:212" end="{{ []}}" req.id=kRMOR7tAH6Jk req.method=GET req.path="/_matrix/client/r0/rooms/!mjbDjyNsRXndKLkHIe:matrix.org/messages" start="{{ []}}" user_id="@pestdoktor:fentker.eu"
time="2020-10-23T14:10:39.666930388Z" level=error msg="ServersAtEvent: failed to load state before event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*backfillRequester).ServersAtEvent" file="github.com/matrix-org/dendrite/roomserver/internal/perform/perform_backfill.go:424" error="storage: missing state for event NID 227185" event_id="$iQG_pXDDalysua3b25-R1yjwVLbSDLRG1_iURva7XbA"
time="2020-10-23T14:10:39.666983716Z" level=info msg="backfilled 0 events" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).backfillViaFederation" file="github.com/matrix-org/dendrite/roomserver/internal/perform/perform_backfill.go:119" room_id="!mjbDjyNsRXndKLkHIe:matrix.org"
time="2020-10-23T14:10:39.667016475Z" level=info msg="Storing new events from backfill" func="github.com/matrix-org/dendrite/syncapi/routing.(*messagesReq).backfill" file="github.com/matrix-org/dendrite/syncapi/routing/messages.go:490" new_events=0 req.id=kRMOR7tAH6Jk req.method=GET req.path="/_matrix/client/r0/rooms/!mjbDjyNsRXndKLkHIe:matrix.org/messages" user_id="@pestdoktor:fentker.eu"
time="2020-10-23T14:10:39.667045620Z" level=info msg=Responding func=github.com/matrix-org/dendrite/syncapi/routing.OnIncomingMessagesRequest file="github.com/matrix-org/dendrite/syncapi/routing/messages.go:172" backwards=true from=t138349_35889 limit=100 req.id=kRMOR7tAH6Jk req.method=GET req.path="/_matrix/client/r0/rooms/!mjbDjyNsRXndKLkHIe:matrix.org/messages" return_end=t0_0 return_start=t138349_35889 to=t0_0 user_id="@pestdoktor:fentker.eu"

Oct 23 '20 14:10 Pestdoktor

Complete log from fresh deployment: Monolith.log

Oct 26 '20 14:10 Pestdoktor

The actual relevant error here is storage: state event IDs missing from the database (8968 != 8969).

I'm also getting these in Dendrite 0.3.4 monolith w/ sqlite on Gentoo.

Dec 25 '20 14:12 stintel

similar errors with polylith

[tnewman@s540 dendrite]$ k logs -f sync-api-88d6d5bd7-8dtpn | grep error
time="2020-12-29T07:00:00.883189292Z" level=error msg="mreq.retrieveEvents failed" func="OnIncomingMessagesRequest\n\t" file=" [github.com/matrix-org/dendrite/syncapi/routing/messages.go:187]" error="PerformBackfill failed: Internal API: 500 from http://room-server.dendrite.svc.cluster.local:7770/api/roomserver/performBackfill: storage: state event IDs missing from the database (1151 != 1152)" req.id=E3GkhTlhY6Of req.method=GET req.path="/_matrix/client/r0/rooms/!yomrOFwgFXzmeMAbzX:matrix.org/messages" user_id="@tnewman:dendrite.travnewmatic.com"
time="2020-12-29T07:02:33.536851366Z" level=error msg="request cancelled" func="OnIncomingSyncRequest\n\t" file=" [github.com/matrix-org/dendrite/syncapi/sync/requestpool.go:203]" device_id=BffwPTDB error="<nil>" limit=20 req.id=LV8rxavfLLDK req.method=GET req.path=/_matrix/client/r0/sync since=s85_0_67_0_46.dl-0-24 timeout=30s user_id="@tnewman:dendrite.travnewmatic.com"
time="2020-12-29T07:03:26.258828311Z" level=error msg="mreq.retrieveEvents failed" func="OnIncomingMessagesRequest\n\t" file=" [github.com/matrix-org/dendrite/syncapi/routing/messages.go:187]" error="PerformBackfill failed: Internal API: 500 from http://room-server.dendrite.svc.cluster.local:7770/api/roomserver/performBackfill: storage: state event IDs missing from the database (1152 != 1153)" req.id=bebMU0qLtQsI req.method=GET req.path="/_matrix/client/r0/rooms/!yomrOFwgFXzmeMAbzX:matrix.org/messages" user_id="@tnewman:dendrite.travnewmatic.com"

Dec 29 '20 07:12 travnewmatic

I've go similar issues when I try to join #dendrite:matrix.org. A lot of missing event IDs Then while it try to backfill, at some point it stop. And now I can see only some message in december 2020, and no more message from today.

I have the v0.3.9 version. At this stage, I can't use Dendrite at all.

Feb 12 '21 07:02 celogeek

I have the v0.3.9 version. At this stage, I can use Dendrite at all.

You meant to say you can't use it?

I'm running dendrite with a recent version from master (f448e8972a1a6974916afc3ab686b342eaf568e2) and I am seeing those issues after trying to join #matrix:matrix.org on my ssqlite based setup. After literally hours of trying to fetch keys from other parties I discovered that line in my logs.

Feb 14 '21 09:02 andir

yes. I can't. I try to join #dentrite. when it complete his backfill, the room was unusable.

Feb 14 '21 09:02 celogeek

I have this problem as well. When joining #dendrite-alerts:matrix.org I get this after a while of backfilling:

ERRO[2021-04-11T12:51:08.658414421Z] [github.com/matrix-org/dendrite/roomserver/internal/perform/perform_backfill.go:143] backfillViaFederation
         backfillViaFederation: failed to get state entries for event  error="storage: state event IDs missing from the database (371 != 372)" event_id="$oYTX6B5ug4NS22JFPD5dTeBJ4pupoD4p5MxOPjDWMZQ"
ERRO[2021-04-11T12:51:08.658889362Z] [github.com/matrix-org/dendrite/syncapi/routing/messages.go:187] OnIncomingMessagesRequest
         mreq.retrieveEvents failed                    error="PerformBackfill failed: storage: state event IDs missing from the database (371 != 372)" req.id=Wq7YCM2IoFLR req.method=GET req.path="/_matrix/client/r0/rooms/!UBhRLVEYYvUWnsljRs:matrix.org/messages" user_id="@darvit:darvit.nl"

It seems this error was added in https://github.com/matrix-org/dendrite/commit/b6ea1bc67ab51667b9e139dd05e0778aca025501 and resides in https://github.com/matrix-org/dendrite/blame/802f1c96f804f7a146e4e12e25b20c980a6af870/roomserver/storage/sqlite3/events_table.go#L229

I am not sure if this is limited to sqlite or also postgresql as backend.

Tested with:

Dendrite 0.3.11+6a35d9f1
SQLite as backend

Apr 11 '21 13:04 milandamen

Has anyone managed to find a workaround to this?

Aug 21 '21 13:08 yousefamar

Just as a data point on this, I also see this issue, and dendrite seems to just chew on the backfill loop forever. But, once someone sends a message to the channel I'm trying to join, events seem to load in element after that. It still doesn't look like it wants to find historical messages past the most recent ones, but at the very least you can join the conversation once a new inbound event arrives in the room.

ex log: time="2021-11-29T00:06:45.593337341Z" level=error msg="backfillViaFederation: failed to get state entries for event" func="github.com/matrix-org/dendrite/roomserver/internal/perform.(*Backfiller).backfillViaFederation" file="github.com/matrix-org/dendrite/roomserver/internal/perform/perform_backfill.go:143" error="storage: state event IDs missing from the database (1263 != 1264)" event_id="$xXPkxHnw8mY8-B9eBbxcMxr6VjlAGo3Rdwu0n9cPHXQ"

Dendrite version or git SHA: 0.5.1+11f588b0
Monolith or Polylith?: monolith
SQLite3 or Postgres?: postgres 13
Running in Docker?: no

Nov 29 '21 00:11 sjahl

Dendrite version or git SHA: v0.6.0 Monolith or Polylith?: monolith SQLite3 or Postgres?: postgres 14 Running in Docker?: yes

I'm running into this error on v0.6.0. I've joined the #dendrite:matrix.org and #fractal:gnome.org channels and am hitting this particular error.

Jan 29 '22 07:01 thefirstofthe300

I'm also seeing this issue with a fresh Dendrite installation.

Dendrite version: 507a8e67739c2cfd89f5be48fdf96bdb0d1698d5. Monolith mode PostgreSQL 12 Bare Ubuntu 12.04, not in Docker Standalone NATS deployment

The issue is that BulkSelectStateEventByID returns a MissingEventError error if you give it, say, 14 events but it can only find 10 of them in the database. I modified roomserver/storage/postgres/events_table.go to log which event IDs are missing, which gives me this list:

$BLXvAdiPVVLfxY-lW3GuJ8TunKU3QPb6MDCxJzHHInE
$NUKCKviAjGMTdcN3OtkjmIq0n8vFIBKLBL8rkMEB9qc
$OQWWJ5pY6ZtixS3R52uUf46cXLjOuM6m7Uh6yIcxY20
$IP3hsgBKg0GbFpM2C1LIhH-z7FgTCzCStltn6ry3VYY

If I pick any of those event IDs at random and grep through the logs for them, I see that the server is trying to pull the events from other servers within the network, and each server is complaining that the "event failed PDU checks" due to a "Bad signature from originating server with ID key ID".

So what I don't know, being new to Matrix, is what the right thing to do here is. If I'm understanding it correctly, it seems like we'd never be able to pull the messages if the originator, for example, loses their signing key and creates a new one. Since the code requires that every event in the provided list be present, that would effectively block backfills the moment some random homeserver's messages can't be verified.

What does Synapse do in this case? Does it mark messages that fail to verify in some "redacted" state, instead of rejecting them entirely, so that backfills can proceed?

Mar 11 '22 21:03 holmosapien

This should be fixed with https://github.com/matrix-org/dendrite/commit/89cd0e8fc13b040470aebe2eb4d36a9235b1473d now.

Jul 01 '22 09:07 S7evinK

assuming this is in 0.8.9, i'm seeing this issue today on a freshly installed Dendrite. Its totally possible this is an issue with my config (monolith with sqlite behind reverse proxy) but this felt like a very similar issue after joining the #dendrite channel.

ERRO[2022-07-03T22:10:44.338693602Z] backfillViaFederation: failed to get state entries for event  error="storage: state event IDs missing from the database (1202 != 1203)" event_id="$Z5RUPrqd4N7G9Ck0sy0VsZtRdcppodv7Rkje6HA-ckA"
ERRO[2022-07-03T22:10:44.339088485Z] mreq.retrieveEvents failed                    error="PerformBackfill failed: storage: state event IDs missing from the database (1202 != 1203)" req.id=F709oPZWLiqA req.method=GET req.path="/_matrix/client/r0/rooms/!RcWPWcZrMeBxOGaalX:matrix.org/messages" user_id="@shoshin:cicadas.surf"
INFO[2022-07-03T22:10:44.543204045Z] Fetched 1211/1212 events from the database   
INFO[2022-07-03T22:10:45.542466552Z] Fetched 1203/1204 events from the database   
INFO[2022-07-03T22:10:46.837753339Z] Fetched 1204/1205 events from the database   
INFO[2022-07-03T22:10:48.038206418Z] Fetched 1204/1205 events from the database   
INFO[2022-07-03T22:10:48.445957394Z] Fetched 1203/1204 events from the database

if i let it run i just constantly get these event fetching logs and then once in a while see that error, not always the same event id.

Dendrite version: 0.8.9 Monolith mode SQLite Debian 11 Built in NATS

Jul 03 '22 22:07 gcentauri

Closing this, as we're now handling these cases less error prone. Also haven't seen this issue reported in #Dendrite in quite a while. If you still see this, I'm happy to re-open the issue.

Oct 20 '22 09:10 S7evinK

Have basically this exact problem right know after joining dendrite:matrix.org.

Dendrite 0.13.1+49d75d3

Aug 19 '23 23:08 Domoel

dendrite dendrite copied to clipboard

Irretrievable event causing backfill failure

Background information

Steps to reproduce

Logs

dendrite
dendrite copied to clipboard