element-hq / element-hq/dendrite

Dendrite panic on syncapi jetstream

Open
#2,798 4 comments 0 reactions 0 assignees View on GitHub
C-Sync-API T-Defect
Dominant language
Go
Stars
965
Forks
101
PR merge metrics
No merged PRs in 30d

Description

*This issue was originally created by [**@hdhog**](https://github.com/hdhog) at .*

### Background information

- **Dendrite version or git SHA**: 0.10.3
- **Monolith or Polylith?**: monolith
- **SQLite3 or Postgres?**: PostgreSQL
- **Running in Docker?**: yes
- **Client used (if applicable)**: server side

### Description

- **What** is the problem: panic on roomeventconsumer and restart
- **Who** is affected: all users
- **How** is this bug manifesting: server restarted
- **When** did this first appear:

last log
```
time="2022-10-16T05:36:09.361354944Z" level=error msg="Failed to acquire database snapshot for sync request" error="context canceled"
time="2022-10-16T05:36:09.361394483Z" level=error msg="Failed to acquire database snapshot for sync request" error="context canceled"
time="2022-10-16T05:36:09.360830889Z" level=error msg="GetEvent: syncDB.NewDatabaseTransaction failed" error="context canceled" event_id="$F79b7RslJn_KLnQYvq2nMH5IoInKsmi-xUimRdlijME" req.id=baXQgUAzTNUS req.method=GET req.path="/_matrix/client/v3/rooms/!KqkRjyTEzAGRiZFBYT:nixos.org/event/$F79b7RslJn_KLnQYvq2nMH5IoInKsmi-xUimRdlijME" room_id="!KqkRjyTEzAGRiZFBYT:nixos.org" user_id="@hdhog:matrix.hdhog.ru"
time="2022-10-16T05:36:11.769729776Z" level=panic msg="roomserver output log: write new event failure" add="[$YS2FFKq3PfAbm5rZsVapvQQaUOKtfs_zcKmVOIUfGlY $5is-LYQo2L0Haoh4wJ67EKsVFftU3NHqO0Z_LGUVor0 $TrcRT6hmenmTx4sXFlQdyrJPUs7j-P-G14Ta-9nXgWs $hhr7lAN-45ZVm5pOyT811j7PRBSzlVlzwI1RGFXALXM $niefVlQsLWPCmAif7xcq_B2_3VSVxvPslwuEI_H3i2o $PchbUq4ZMRxlwRJ5swdEfKAJ_82qv6cWqxLOO1xojt8 $BrrQ-dZEjblxISqA5A2p5xeY6dyeCGM0dhzahnBfc3c $U4wLJalKSW4121plydlljXuQIuGQbajJixEjTJ434CA $xOtP2LpV1G6M_oNeTTIGZRm7MDSr0iazC_lkB4kcPaQ $zvvoRHW6au4L0ULlR-h9ab91dew8mEBNwqh-kNNhiAw $G8uY3lglKCJ8pYuKiQnSb8vIKmQcDFWnInrKcs14jJw $NJl3afzuiDMrdFQQeMF2MfpO0TEUHyAUwHOxTkUwSgs $jC49UmRBEiK6eINbjZTOuK6SkdjylTEe8wL5oJaMDTc $iCP64E_d2vEiyVibAayhV02JkgXEGExZqkAEQS8PeIY $-_iX7bsQXPwB5295idBk_mHTyGtckPTeXv3kmtFUs4A $htYw1h5eSQnAyeLCX5iEvD3g8py_onUuDDtAoOcAixQ $LcGmh_WuLiRemXtxfUPmLA72PR_glrToClYcbvrOQ2A $VzR6JVw7rBOUQLKlEC5JPNDGID_B4urhFnJKnMaeurE $pzx2HKdHiKCqxoEt9R5GpiYDAHrllHE579c8OhHUKZ4 $7i5cEV5x7nZPTv441QqxKY4r-lSSnA443Hoh6lRhJdc $KjRNcuHTMcJ4XakXUEji2d9Ub6PTmD5-m2u7MCcQDXk $IZop0HSKRmJfVxbZnWzrftIHA-Y9u4YeWWscr03_3EE
*********** remove many lines ***************
$Ufq4UZ6ladgf1FqA7XVZfwBbizdhH-0Xx_ybCEBygw8 $45OF-eEYm2WWXGH3wGxz49rtVdgT1Vd-k8nxenxYA00 $p1Ci-g2ZziSjtc_Slkr5T8G49H-DTwoH3QmYSXuc1pc $ro1kl07V4kGvchP46CKuy2MRqXZT8gOG6m8u5NanTPg $jVDY1ylN7vKKRB5nHTsqQH75ciiUUUcP8F2zGyOi1r8 $m7P9jSYBAjTJYPucNSB4riJDqHH-se8qGRt870vcY_I $UxQJR2PBUr4DFe-LGio_t-YKM_rhjEWYsWBV-iP2hp8 $xykKCbew2hPcsCrQ5U17BmqphKibuem2E3N1zUGou8o $U9ty-KAq3LoWItQsneBK-cKU-O_5DUYlj8VSWE22uLw $4UYWA-gkeH6Nw__q31YetLNrqabrDOourz2wF2D_LoU $bwfQxLXwtVOzcIVqFg3C699ilRmwsCXbml97tdqnJ0A $1sbPWaxLoIyvSNze_-HTezevxzqpEMeJXqJs-cBBmKo $fyKPjuYFD9kJa5AuNCxKJU2w6jdfkDZGrNOW5Flfxu0 $PvHT3jwSVyYZarPkS8htCu8VO-9p72NHz9Vhi0XNdf4 $3VSXkMquI3Qws-OZp-EQQtCpYnHD4Z7dRDfbDH314FI $iNKlqw5Mgr7VVztgeyVfFtlzuKSHgUxHiOxqdbQv3i8 $3-JzdCPmygNacTss0Z3OCWqOqm4tsXq02ogeIaJ0z7o $K_f6OzBIMU7fZ6492-XlBxU2MbCV7_Bmo4fcM25WIdc $TZTzwyJLsBYLJtXPGUx2XLix_K99cWZUXOI-ljPk_cE $DrR6RaYk_eNKET4ZclFakjLAYQobEYUwKw7TRmHyXWk $HmDvRbETeGpn_ka7pv-ie7f6k5mKPBh1lGBT7DQWTAg $ZhQQgvz-W62kHSivJq1tntxK8RVJuudjS8MkQEMvxt0 $TnspHK9FpkAzuejtC7jGC27kQnl_X_XTGNvLJLQAFjY $KECPPOz-DNEDcKYPp7SFHXcJd8JpER9XJXI6NpTOcpI $H-PzC1Y6NtzOcTl-B55e9WFuMDkEnmj_sYyXFKpT7l4 $8-rjdtvxaTSEtKp3hyPPx3nWhitpb-qVB3uWBJO8skg $2ZsBe-u4Ijzl4yjLpM7VZX7LV-jEtG6HIpzOvNuyAYE $HO6LKWASWzvdX5b50H82hEmS-l8KRFjV2EJdXT8qpyA $iASnZDDA2HVU8JbYFIWT3bV8mZBNejEXh34bswkSqkI $lxIaVm2WPtvM6jJlLz2rPesFORyOz8XRgsoYeZ5oQow $3IiZmItu-8Vc3vqAImVcVeNLhEtrSrXiVyEwbI13FoU $JPSPp9_vXyvsFc77fHe6uB7OsTvR-iA98cza7w81iCQ $mc84WsQXmUO3mvARUMYeyBVSNZctxlduxElRWBFa5ps $U-HLCH4oORY3kjBNyPSKdcfPXELSaoTKo5Uv6VyfGQM $d6tto_Nc0lfJu61pdq7CqUMK6nU41k42pGVM2-UGwLA $LvTDk6mzTVw3556vkIZ1O294pcf0twiv3xo1wME9_6U $vtK04MbnO5ac3Z31Fk60DYSQH6wu2Ywfn-qF1YC7mtw $eSBJNfIRjqhKjhzaP6iEDMMT2hDq58E_KS7Icm_Kfq0 $Jllq1-gajPNu1H8tdPb67Zzmu2Ct8XrPdZ7FNWX8UMo $e7a6dH_yLunuKyOk_ca4Bw9gcCTz8zw1eLCP6N3359w $vlY4XIoZfHd0pVibJVrqHmPFJJoFEQjeD5r3OYN1NsY $87K12_1jJwL3YhjwfiUTsZB6ZNl4I8g7mnIXTUY8iQ4 $4L5FbL3JObcNs_8AxTfQdXpqpqsEKevyBKSJQNAl5_g $BH0zYB2Uy9vUif72qMnXRv1tiw1RGlI7A_dtSDkCthw $IYHMO4WxDsHiEwCI2RG7KiuWgtTSGmn-pzJVtcNS75w $XB8ODTGqmWue_kzaCwfZDarPETS69-P131GoLy7Yj4w $pFcpGUMoshGN5VnJSXa98WOUaFyGVWgncN16V3d1hok $TOfKRr4kXU8-siQfvcUurfALzyJZMACftTckIq7I5YI $HdwRGEaz5rYmEdc7aR1gazoGRU-ockfmJcvRVyFweIo]" del="[]" error="d.Memberships.UpsertMembership: pq: duplicate key value violates unique constraint \"syncapi_memberships_unique\"" event="{\"auth_events\":[\"$YS2FFKq3PfAbm5rZsVapvQQaUOKtfs_zcKmVOIUfGlY\",\"$LKsl93OKRQ-_S9qJcDcZZB4vpBQ9EQXRjt1HbohkYVE\",\"$TrcRT6hmenmTx4sXFlQdyrJPUs7j-P-G14Ta-9nXgWs\",\"$5is-LYQo2L0Haoh4wJ67EKsVFftU3NHqO0Z_LGUVor0\"],\"content\":{\"avatar_url\":\"mxc://lassul.us/mSBytdnmcCoAFjWHVslfgOJw\",\"displayname\":\"lassulus\",\"membership\":\"invite\"},\"depth\":7147,\"hashes\":{\"sha256\":\"VPR4Nz1glRDZNzyqxHY675lIJuPAHb8pS1J/IaVO4eQ\"},\"origin\":\"nixos.dev\",\"origin_server_ts\":1665833783154,\"prev_events\":[\"$bwfQxLXwtVOzcIVqFg3C699ilRmwsCXbml97tdqnJ0A\",\"$Hwf9cce64pn0EgrXWEuAgFRKlCw5NPKIxCkxrwyOrMw\"],\"room_id\":\"!MKvhXlSTLGJUXpYuWF:nixos.org\",\"sender\":\"@lassulus:nixos.dev\",\"signatures\":{\"lassul.us\":{\"ed25519:a_MvbO\":\"d0fWw/wLDVxlEUQsxCP/ecgchdlfsy0JpXqIhhBuiOccHg+OqYA8qRgZIAJWTcGvppj0tJlzOFNOIpY7IDfRBg\"},\"nixos.dev\":{\"ed25519:a_NQWV\":\"QRcTd1lrgb/xITfHoHTL1PdWb2J4fYz/qeHEA/FEig9rCJYY0qT9VyMz2C0AwNR+x03OXbviYqaP1vMoi/bHCg\"}},\"state_key\":\"@lassulus:lassul.us\",\"type\":\"m.room.member\"}" event_id="$_HgVf2QlLSWPB8OC49jFsGihPqb3o-Q7IV6Kz3ln9Pg"
panic: (*logrus.Entry) 0xc011f04070

goroutine 405 [running]:
github.com/sirupsen/logrus.(*Entry).log(0xc011f04000, 0x0, {0xc00b9140f0, 0x2e})
github.com/sirupsen/logrus@v1.9.0/entry.go:260 +0x4a7
github.com/sirupsen/logrus.(*Entry).Log(0xc011f04000, 0x0, {0xc011eda898?, 0xc011eda8f8?, 0x0?})
github.com/sirupsen/logrus@v1.9.0/entry.go:304 +0x4f
github.com/sirupsen/logrus.(*Entry).Panic(...)
github.com/sirupsen/logrus@v1.9.0/entry.go:342
github.com/MFAshby/stdemuxerhook.(*StdDemuxerHook).Fire(0x0?, 0xc006ac3f80)
github.com/MFAshby/stdemuxerhook@v1.0.0/stdemuxerhook.go:58 +0x19e
github.com/sirupsen/logrus.LevelHooks.Fire(0xc011eda9d8?, 0x11eda9a8?, 0x4?)
github.com/sirupsen/logrus@v1.9.0/hooks.go:28 +0x82
github.com/sirupsen/logrus.(*Entry).fireHooks(0xc006ac3f80)
github.com/sirupsen/logrus@v1.9.0/entry.go:280 +0x1dc
github.com/sirupsen/logrus.(*Entry).log(0xc006ac3f10, 0x0, {0xc00b9140c0, 0x2e})
github.com/sirupsen/logrus@v1.9.0/entry.go:242 +0x390
github.com/sirupsen/logrus.(*Entry).Log(0xc006ac3f10, 0x0, {0xc011edac98?, 0x0?, 0x0?})
github.com/sirupsen/logrus@v1.9.0/entry.go:304 +0x4f
github.com/sirupsen/logrus.(*Entry).Logf(0xc006ac3f10, 0x0, {0x187ec27?, 0x3?}, {0x0?, 0x0?, 0xc012d105c0?})
github.com/sirupsen/logrus@v1.9.0/entry.go:349 +0x85
github.com/sirupsen/logrus.(*Entry).Panicf(...)
github.com/sirupsen/logrus@v1.9.0/entry.go:387
github.com/matrix-org/dendrite/syncapi/consumers.(*OutputRoomEventConsumer).onNewRoomEvent(0xc0041e7b80, {0x1ad6ef0, 0xc0043b2720}, {0xc018f0b590, 0x1, {0xc00bd3f580, 0x1, 0x4}, {0xc016772000, 0xecf, ...}, ...})
github.com/matrix-org/dendrite/syncapi/consumers/roomserver.go:268 +0xd55
github.com/matrix-org/dendrite/syncapi/consumers.(*OutputRoomEventConsumer).onMessage(0xc0041e7b80, {0xc015bf9de0?, 0xc00f4139c0?}, {0xc012d1a4e8?, 0xc00f4139c0?, 0xc00fd97a60?})
github.com/matrix-org/dendrite/syncapi/consumers/roomserver.go:117 +0x3f8
github.com/matrix-org/dendrite/setup/jetstream.JetStreamConsumer.func2()
github.com/matrix-org/dendrite/setup/jetstream/helpers.go:91 +0x71e
created by github.com/matrix-org/dendrite/setup/jetstream.JetStreamConsumer
github.com/matrix-org/dendrite/setup/jetstream/helpers.go:43 +0x31e

```

Contributor guide

Open the contributing guide

Research direction

Start in syncapi/consumers/roomserver.go around line 268, then trace the JetStream consumer through setup/jetstream/helpers.go around lines 43 and 91. Reproduce the reported panic with the PostgreSQL monolith setup and use the duplicate syncapi_memberships_unique error as the trigger. Done means the room event is handled without panicking or restarting the server.

Written by the indexing model from the issue text.

Assessment

Tech stack
go, postgresql
Domain
backend, databases
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
25/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.