element-x-ios icon indicating copy to clipboard operation
element-x-ios copied to clipboard
verified publisher icon element-hq

Notifications don't contain content after login

Open marwing opened this issue 1 year ago • 8 comments

Steps to reproduce

  1. Logout of existing session
  2. Log in to new session
  3. verify session (optional)
  4. Receive notifications

Outcome

What did you expect?

Notifications should contain the event information (sender, room, content, avatar)

What happened instead?

After a logout/login every single notification from encrypted and unencrypted rooms is missing the notification content. From experience, I can say that this will probably fix itself after a few days with this session; however, the last time I logged out and back in was a few months ago, so I don't (yet) know if this is still accurate.

IMG_0156-obfuscated

Your phone model

iPad Pro

Operating system version

iPadOS 17.4

Application version

1.5.10 (94)

Homeserver

Synapse 1.102.0 / Proxy 0.99.15

Will you send logs?

Yes

marwing avatar Mar 06 '24 15:03 marwing

@marwing Looking at the logs your app is attempting to refresh your access token with your homeserver in the notifications process. Would you mind signing out, deleting the app, reinstalling (v1.5.10) and telling us if this continues?

pixlwave avatar Mar 07 '24 14:03 pixlwave

Reinstalling the app seems to have fixed it.

marwing avatar Mar 07 '24 15:03 marwing

However, logging out and back in again without reinstalling, seems to reliably break it.

marwing avatar Mar 07 '24 15:03 marwing

Rebooting the device also seems to fix this issue, so maybe the NSE works with old data/tokens until restarted?

marwing avatar Mar 07 '24 16:03 marwing

Would you mind sending some more logs please so we can see what's going on?

pixlwave avatar Mar 07 '24 16:03 pixlwave

Done.

marwing avatar Mar 07 '24 16:03 marwing

Alright, I had a look and I believe it may be an issue between your sliding sync proxy and homeserver. The app sends a request to /sync and the proxy first makes a /whoami request which is failing because of an expired access token (apparently).

It's very weird that the error is only popping up in the notifications process - the main app never sees an expired token or attempts to refresh any token. I would suggest double checking that you have token refresh disabled on your server, and if you do, trying a clean proxy installation in case something is up in the db.

pixlwave avatar Mar 11 '24 14:03 pixlwave

Token refresh is disabled. I just reproduced this twice, each time with a fresh proxy database and reinstalled app. I have sent app logs again and attached the last proxy logs below.

According to the logs, the NSE sends an unknown access token (my guess would be an old one):

19:23:16 INF Received connection from unknown access token, querying with homeserver
19:23:16 WRN failed to get or create Conn error="HTTP 401 : /whoami returned HTTP 401"
proxy logs (from container start to stop) 
Sync v3 [0.99.15] (bbb886e)
Debug=false LogLevel= MaxConns=0
2024/03/11 19:12:25 OK   20230728114555_device_data_drop_id.sql (6.66ms)
2024/03/11 19:12:25 OK   20230802121023_device_data_jsonb.go (27.19ms)
2024/03/11 19:12:25 OK   20230814183302_cbor_device_data.go (14.41ms)
2024/03/11 19:12:25 OK   20230822180807_bogus_snapshot_cleanup.go (3.26ms)
2024/03/11 19:12:25 OK   20230913120537_events_missing_previous.sql (1.77ms)
2024/03/11 19:12:25 OK   20231019153023_cleanup_dead_invites.sql (6.71ms)
19:12:25 INF invalidating users len_invalidate_users=0
19:12:25 INF invalidating users invalidate_users=[]
19:12:25 INF reset since tokens num_devices=0
19:12:25 INF reset invites num_invites=0
2024/03/11 19:12:25 OK   20231108122539_clear_stuck_invites.go (5.19ms)
2024/03/11 19:12:25 goose: successfully migrated database to version: 20231108122539
19:12:25 INF creating handler
19:12:25 INF retrieved global snapshot from database
19:12:25 INF listening on 0.0.0.0:8008
19:12:25 INF StartV2Pollers num_devices=0 num_fail_decrypt=0
19:12:25 INF StartV2Pollers finished
19:13:22 INF Received connection from unknown access token, querying with homeserver
19:13:22 INF Received connection from unknown access token, querying with homeserver
19:13:22 INF EnsurePolling: new request device_id=WYCEPZWJMT user_id=@rntpts:synapse.rntpts.de
19:13:22 INF EnsurePolling: preprocessing done device_id=WYCEPZWJMT user_id=@rntpts:synapse.rntpts.de
19:13:22 INF Poller: v2 poll loop started device_id=WYCEPZWJMT since= user_id=@rntpts:synapse.rntpts.de
19:13:35 INF Poller: valid initial sync response received device_id=WYCEPZWJMT user_id=@rntpts:synapse.rntpts.de
19:14:06 INF Poller: accumulated data device [events,changed,left,account]=[0,0,0,43] device_id=WYCEPZWJMT rooms [timeline,state,typing,receipts,invites]=[64,64,1,63,0] user_id=@rntpts:synapse.rntpts.de
19:14:06 INF created new connection conn=room-list device=WYCEPZWJMT user=@rntpts:synapse.rntpts.de
19:14:06 INF created new connection conn=encryption device=WYCEPZWJMT user=@rntpts:synapse.rntpts.de
19:14:06 INF b=0/0/2000 c=encryption dev=WYCEPZWJMT duration=44.139(44.123+0.016) p=0 q=1 r=0 size=225 status=200 t=9d7453b944e4475b97fc14578e7c9bb7 u=@rntpts:synapse.rntpts.de
19:14:06 INF b=1/0/2000 c=encryption dev=WYCEPZWJMT duration=0.005(0.001+0.004) p=1 q=2 r=0 size=181 status=200 u=@rntpts:synapse.rntpts.de
19:14:07 INF b=0/0/2000 c=encryption dev=WYCEPZWJMT dl-c=1 duration=0.006(0.001+0.005) p=2 q=3 r=0 size=153 status=200 u=@rntpts:synapse.rntpts.de
19:14:07 INF ag=43 b=1/1/2000 c=room-list dev=WYCEPZWJMT duration=44.446(44.116+0.327) l=2 p=0 q=1 r=20 size=164359 status=200 t=2d83c7ac2d7c42edba11be6311453ea0 u=@rntpts:synapse.rntpts.de
19:14:08 INF client has resent this pos with different request data pos=1
19:14:08 WRN failed to JSON-encode result error="HTTP 499 : write tcp 172.18.2.9:8008->172.18.2.4:45082: write: broken pipe"
19:14:08 INF b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=0.102(0.098+0.001) l=3 p=1 q=2 r=44 size=212356 status=200 t=8c189766c8cf4fa28df6c509718c5269 u=@rntpts:synapse.rntpts.de
19:14:08 INF c=room-list dev=WYCEPZWJMT duration=0.001 l=3 p=2 q=3 r=0 size=212 status=200 t=9d9dacad1da1484682f85a1e8f7fbc21 u=@rntpts:synapse.rntpts.de
19:14:09 INF b=2/0/2000 c=room-list dev=WYCEPZWJMT duration=1.751(0.001+0.746) l=3 p=1 q=2 r=44 size=3785 status=200 t=823d04969a324a2594ad0be26593c21f u=@rntpts:synapse.rntpts.de
19:14:26 INF b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=17.781(0.001+0.000) l=3 p=3 q=4 r=1 size=728 status=200 t=45e14d38e1704d30a98f682157ca0279 u=@rntpts:synapse.rntpts.de
19:14:26 INF b=1/0/2000 c=room-list dev=WYCEPZWJMT duration=0.003(0.001+0.000) l=3 p=4 q=5 r=0 size=322 status=200 u=@rntpts:synapse.rntpts.de
19:14:26 INF b=0/0/2000 c=encryption dev=WYCEPZWJMT duration=19.040(0.001+0.000) p=3 q=4 r=0 size=146 status=200 u=@rntpts:synapse.rntpts.de
19:14:28 INF b=0/0/2000 c=encryption d=1 dev=WYCEPZWJMT duration=2.164(0.001+0.000) p=4 q=5 r=0 size=317 status=200 u=@rntpts:synapse.rntpts.de
19:14:29 INF b=0/0/2000 c=encryption d=1 dev=WYCEPZWJMT duration=1.142(0.001+0.000) p=5 q=6 r=0 size=456 status=200 u=@rntpts:synapse.rntpts.de
19:14:29 INF b=0/0/2000 c=encryption d=1 dev=WYCEPZWJMT duration=0.066(0.001+0.000) p=6 q=7 r=0 size=278 status=200 u=@rntpts:synapse.rntpts.de
19:14:35 INF b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=9.535(0.001+0.000) l=3 p=5 q=6 r=1 size=742 status=200 u=@rntpts:synapse.rntpts.de
19:14:35 INF b=0/0/2000 c=encryption d=1 dev=WYCEPZWJMT duration=6.097(0.001+0.000) p=7 q=8 r=0 size=454 status=200 u=@rntpts:synapse.rntpts.de
19:14:36 INF b=0/0/2000 c=encryption d=1 dev=WYCEPZWJMT duration=0.275(0.001+0.000) p=8 q=9 r=0 size=227 status=200 u=@rntpts:synapse.rntpts.de
19:14:36 INF b=1/0/2000 c=encryption dev=WYCEPZWJMT dl-c=1 duration=0.010(0.001+0.000) p=9 q=10 r=0 size=157 status=200 u=@rntpts:synapse.rntpts.de
19:14:36 WRN Client did not increment since token: possibly sending back duplicate to-device events! device=WYCEPZWJMT initial=false last_sent=8 recv=5 user=@rntpts:synapse.rntpts.de
19:14:36 INF b=1/0/2000 c=encryption d=3 dev=WYCEPZWJMT duration=0.011(0.001+0.004) p=10 q=11 r=0 size=740 status=200 u=@rntpts:synapse.rntpts.de
19:14:36 WRN Client did not increment since token: possibly sending back duplicate to-device events! device=WYCEPZWJMT initial=false last_sent=9 recv=8 user=@rntpts:synapse.rntpts.de
19:14:36 INF b=1/0/2000 c=encryption d=1 dev=WYCEPZWJMT duration=0.009(0.001+0.004) p=11 q=12 r=0 size=300 status=200 u=@rntpts:synapse.rntpts.de
19:14:36 INF ToDeviceTable.Messages device=WYCEPZWJMT msgid=7fcab9de-3156-4ff4-9fb0-bc1eca383aca user=@rntpts:synapse.rntpts.de
19:14:36 INF b=0/0/2000 c=encryption d=1 dev=WYCEPZWJMT duration=0.056(0.001+0.000) p=12 q=13 r=0 size=1151 status=200 u=@rntpts:synapse.rntpts.de
19:14:36 INF ToDeviceTable.Messages device=WYCEPZWJMT msgid=da65d57b-1a8a-49a0-ad01-900dcbea4b35 user=@rntpts:synapse.rntpts.de
19:14:36 INF ToDeviceTable.Messages device=WYCEPZWJMT msgid=b69625a7-992c-4812-a162-8b634d356b2a user=@rntpts:synapse.rntpts.de
19:14:36 WRN Client did not increment since token: possibly sending back duplicate to-device events! device=WYCEPZWJMT initial=false last_sent=12 recv=10 user=@rntpts:synapse.rntpts.de
19:14:36 INF ToDeviceTable.Messages device=WYCEPZWJMT msgid=da65d57b-1a8a-49a0-ad01-900dcbea4b35 user=@rntpts:synapse.rntpts.de
19:14:36 INF ToDeviceTable.Messages device=WYCEPZWJMT msgid=b69625a7-992c-4812-a162-8b634d356b2a user=@rntpts:synapse.rntpts.de
19:14:36 INF b=1/0/2000 c=encryption d=2 dev=WYCEPZWJMT duration=0.011(0.001+0.006) p=13 q=14 r=0 size=2272 status=200 u=@rntpts:synapse.rntpts.de
19:14:36 INF ToDeviceTable.Messages device=WYCEPZWJMT msgid=b705e9fa-d744-41f8-92e2-f7043469911c user=@rntpts:synapse.rntpts.de
19:14:36 WRN Client did not increment since token: possibly sending back duplicate to-device events! device=WYCEPZWJMT initial=false last_sent=14 recv=12 user=@rntpts:synapse.rntpts.de
19:14:36 INF ToDeviceTable.Messages device=WYCEPZWJMT msgid=b705e9fa-d744-41f8-92e2-f7043469911c user=@rntpts:synapse.rntpts.de
19:14:36 WRN Client did not increment since token: possibly sending back duplicate to-device events! device=WYCEPZWJMT initial=false last_sent=14 recv=12 user=@rntpts:synapse.rntpts.de
19:14:36 INF ToDeviceTable.Messages device=WYCEPZWJMT msgid=b705e9fa-d744-41f8-92e2-f7043469911c user=@rntpts:synapse.rntpts.de
19:14:36 INF b=2/0/2000 c=encryption d=2 dev=WYCEPZWJMT duration=0.010(0.001+0.004) p=14 q=15 r=0 size=1344 status=200 u=@rntpts:synapse.rntpts.de
19:14:36 INF Poller: accumulated data device [events,changed,left,account]=[16,2,0,0] device_id=WYCEPZWJMT rooms [timeline,state,typing,receipts,invites]=[0,0,2,2,0] user_id=@rntpts:synapse.rntpts.de
19:14:36 WRN Client did not increment since token: possibly sending back duplicate to-device events! device=WYCEPZWJMT initial=false last_sent=16 recv=14 user=@rntpts:synapse.rntpts.de
19:14:36 INF b=1/0/2000 c=encryption d=2 dev=WYCEPZWJMT duration=0.010(0.001+0.006) p=15 q=16 r=0 size=542 status=200 u=@rntpts:synapse.rntpts.de
19:14:46 INF b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=10.439(0.001+0.000) l=3 p=6 q=7 r=0 size=251 status=200 u=@rntpts:synapse.rntpts.de
19:14:46 INF b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=0.041(0.001+0.000) l=3 p=7 q=8 r=0 size=339 status=200 u=@rntpts:synapse.rntpts.de
19:14:49 INF b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=2.797(0.001+0.000) l=3 p=8 q=9 r=0 size=227 status=200 u=@rntpts:synapse.rntpts.de
19:14:49 INF b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=0.014(0.001+0.000) l=3 p=9 q=10 r=0 size=318 status=200 u=@rntpts:synapse.rntpts.de
19:14:52 INF b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=3.512(0.001+0.000) l=3 p=10 q=11 r=1 size=1858 status=200 u=@rntpts:synapse.rntpts.de
19:14:54 INF b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=1.372(0.001+0.000) l=3 p=11 q=12 r=1 size=1708 status=200 u=@rntpts:synapse.rntpts.de
19:14:56 INF b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=2.434(0.001+0.000) l=3 p=12 q=13 r=0 size=334 status=200 u=@rntpts:synapse.rntpts.de
19:14:56 INF b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=0.020(0.001+0.000) l=3 p=13 q=14 r=0 size=343 status=200 u=@rntpts:synapse.rntpts.de
19:15:06 INF c=encryption dev=WYCEPZWJMT duration=30.005(0.001+0.000) p=16 q=17 r=0 size=82 status=200 u=@rntpts:synapse.rntpts.de
19:15:11 INF c=room-list dev=WYCEPZWJMT duration=14.651(0.001+0.000) l=3 p=14 q=15 r=0 size=126 status=200 u=@rntpts:synapse.rntpts.de
19:15:11 INF client has resent this pos with different request data pos=14
19:15:11 INF b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=0.013(0.001+0.012) l=3 p=14 q=15 r=0 size=126 status=200 sub=1 t=4718fac98ec343cf89bae0673ae2785b u=@rntpts:synapse.rntpts.de
19:15:11 INF c=room-list dev=WYCEPZWJMT duration=0.001 l=3 p=15 q=16 r=1 size=1926 status=200 sub=1 t=700af609d2964965b7b48ef87b59b775 u=@rntpts:synapse.rntpts.de
19:15:11 INF Poller: accumulated data device [events,changed,left,account]=[0,0,0,0] device_id=WYCEPZWJMT rooms [timeline,state,typing,receipts,invites]=[2,0,2,4,0] user_id=@rntpts:synapse.rntpts.de
19:15:11 INF b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=0.290(0.001+0.000) l=3 p=16 q=17 r=0 size=374 status=200 sub=1 t=ec3eab678b1849bd83cdc89d42fc30ed u=@rntpts:synapse.rntpts.de
19:15:11 INF b=0/0/2000 c=encryption dev=WYCEPZWJMT duration=4.931(0.001+0.000) p=17 q=18 r=1 size=166 status=200 u=@rntpts:synapse.rntpts.de
19:15:11 INF b=1/0/2000 c=room-list dev=WYCEPZWJMT duration=0.004(0.001+0.000) l=3 p=17 q=18 r=1 size=436 status=200 u=@rntpts:synapse.rntpts.de
19:15:23 INF b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=11.396(0.001+0.000) l=3 p=18 q=19 r=0 size=252 status=200 u=@rntpts:synapse.rntpts.de
19:15:23 INF b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=0.435(0.001+0.000) l=3 p=19 q=20 r=0 size=232 status=200 u=@rntpts:synapse.rntpts.de
19:15:24 INF b=0/0/2000 c=encryption dev=WYCEPZWJMT duration=12.177(0.001+0.000) p=18 q=19 r=0 size=145 status=200 u=@rntpts:synapse.rntpts.de
19:15:24 INF ToDeviceTable.Messages device=WYCEPZWJMT msgid=9751331f-4c29-442f-8c1f-561c8b6b4592 user=@rntpts:synapse.rntpts.de
19:15:24 INF b=0/0/2000 c=encryption d=1 dev=WYCEPZWJMT duration=0.629(0.001+0.000) p=19 q=20 r=0 size=1677 status=200 u=@rntpts:synapse.rntpts.de
19:15:24 INF b=0/0/2000 c=encryption dev=WYCEPZWJMT duration=0.006(0.001+0.005) p=20 q=21 r=0 size=145 status=200 u=@rntpts:synapse.rntpts.de
19:15:25 INF b=0/0/2000 c=encryption dev=WYCEPZWJMT duration=0.336(0.001+0.000) p=21 q=22 r=1 size=166 status=200 u=@rntpts:synapse.rntpts.de
19:15:25 INF b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=1.369(0.001+0.000) l=3 p=20 q=21 r=1 size=1711 status=200 u=@rntpts:synapse.rntpts.de
19:15:26 INF created new connection conn=notifications device=WYCEPZWJMT user=@rntpts:synapse.rntpts.de
19:15:26 INF ag=43 b=0/0/2000 c=notifications dev=WYCEPZWJMT duration=0.012(0.005+0.006) l=1 p=0 q=1 r=1 size=23501 status=200 sub=1 t=64ec4c52cd524e6c818b4e68cfb53977 u=@rntpts:synapse.rntpts.de
19:15:35 INF b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=9.603(0.001+0.000) l=3 p=21 q=22 r=0 size=330 status=200 u=@rntpts:synapse.rntpts.de
19:15:35 INF b=0/0/2000 c=encryption dev=WYCEPZWJMT duration=9.638(0.001+0.000) p=22 q=23 r=1 size=166 status=200 u=@rntpts:synapse.rntpts.de
19:15:35 INF b=1/0/2000 c=room-list dev=WYCEPZWJMT duration=0.003(0.001+0.000) l=3 p=22 q=23 r=1 size=543 status=200 u=@rntpts:synapse.rntpts.de
19:15:38 INF c=room-list dev=WYCEPZWJMT duration=2.932(0.001+0.000) l=3 p=23 q=24 r=0 size=126 status=200 u=@rntpts:synapse.rntpts.de
19:15:38 INF c=encryption dev=WYCEPZWJMT duration=2.949(0.001+0.000) p=23 q=24 r=0 size=82 status=200 u=@rntpts:synapse.rntpts.de
19:15:39 INF created new connection conn=encryption device=WYCEPZWJMT user=@rntpts:synapse.rntpts.de
19:15:39 INF b=0/0/2000 c=encryption dev=WYCEPZWJMT duration=0.008(0.005+0.003) p=0 q=1 r=0 size=245 status=200 t=b0b934e301e944c580ecae7972c58816 u=@rntpts:synapse.rntpts.de
19:15:39 INF created new connection conn=room-list device=WYCEPZWJMT user=@rntpts:synapse.rntpts.de
19:15:40 INF ag=43 b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=0.273(0.007+0.263) l=2 p=0 q=1 r=20 size=166089 status=200 t=7dac8b7a9b594c5384e37a4f2a3374b5 u=@rntpts:synapse.rntpts.de
19:15:40 INF client has resent this pos with different request data pos=1
19:15:40 WRN failed to JSON-encode result error="HTTP 499 : write tcp 172.18.2.9:8008->172.18.2.4:40898: write: broken pipe"
19:15:40 INF b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=0.369(0.364+0.002) l=3 p=1 q=2 r=44 size=218061 status=200 t=4c56ae6cddbb4c349c3abd0b8da0d094 u=@rntpts:synapse.rntpts.de
19:15:40 INF c=room-list dev=WYCEPZWJMT duration=0.001 l=3 p=2 q=3 r=0 size=212 status=200 t=014a0379c4804dc8afda8447193cf73f u=@rntpts:synapse.rntpts.de
19:15:41 INF b=0/0/2000 c=room-list dev=WYCEPZWJMT duration=1.576(0.001+0.571) l=3 p=1 q=2 r=44 size=3785 status=200 t=bae65d4bbd3e4b77bf8262cb5667b3f2 u=@rntpts:synapse.rntpts.de
19:15:45 INF c=encryption dev=WYCEPZWJMT duration=5.307(0.001+0.000) p=1 q=2 r=0 size=81 status=200 u=@rntpts:synapse.rntpts.de
19:15:45 INF c=room-list dev=WYCEPZWJMT duration=4.073(0.001+0.000) l=3 p=3 q=4 r=0 size=169 status=200 t=c912001600824b1aae2d05e2fd31d924 u=@rntpts:synapse.rntpts.de
19:15:45 INF Poller: accumulated data device [events,changed,left,account]=[1,1,0,0] device_id=WYCEPZWJMT rooms [timeline,state,typing,receipts,invites]=[2,0,2,3,0] user_id=@rntpts:synapse.rntpts.de
19:15:45 WRN poller: access token has been invalidated, terminating loop device_id=WYCEPZWJMT user_id=@rntpts:synapse.rntpts.de
19:15:45 INF Poller: accumulated data device [events,changed,left,account]=[0,0,0,0] device_id=WYCEPZWJMT rooms [timeline,state,typing,receipts,invites]=[0,0,0,0,0] user_id=@rntpts:synapse.rntpts.de
19:15:45 INF closing connection due to expired TTL in cache conn=@rntpts:synapse.rntpts.de|WYCEPZWJMT|room-list
19:15:45 INF closing connection due to expired TTL in cache conn=@rntpts:synapse.rntpts.de|WYCEPZWJMT|encryption
19:15:45 INF closing connection due to expired TTL in cache conn=@rntpts:synapse.rntpts.de|WYCEPZWJMT|notifications
19:17:12 INF Received connection from unknown access token, querying with homeserver
19:17:12 INF Received connection from unknown access token, querying with homeserver
19:17:12 INF EnsurePolling: new request device_id=ZKINVXQGHQ user_id=@rntpts:synapse.rntpts.de
19:17:12 INF EnsurePolling: preprocessing done device_id=ZKINVXQGHQ user_id=@rntpts:synapse.rntpts.de
19:17:12 INF Poller: v2 poll loop started device_id=ZKINVXQGHQ since= user_id=@rntpts:synapse.rntpts.de
19:17:39 INF Poller: valid initial sync response received device_id=ZKINVXQGHQ user_id=@rntpts:synapse.rntpts.de
19:17:46 INF Poller: accumulated data device [events,changed,left,account]=[0,0,0,43] device_id=ZKINVXQGHQ rooms [timeline,state,typing,receipts,invites]=[64,64,2,63,0] user_id=@rntpts:synapse.rntpts.de
19:17:46 INF created new connection conn=encryption device=ZKINVXQGHQ user=@rntpts:synapse.rntpts.de
19:17:46 INF created new connection conn=room-list device=ZKINVXQGHQ user=@rntpts:synapse.rntpts.de
19:17:46 INF b=0/0/2000 c=encryption dev=ZKINVXQGHQ duration=34.162(34.153+0.009) p=0 q=1 r=0 size=225 status=200 t=bfe25983a9ec47ba8e58ec6c20c19da9 u=@rntpts:synapse.rntpts.de
19:17:46 INF b=0/0/2000 c=encryption dev=ZKINVXQGHQ duration=0.007(0.002+0.006) p=1 q=2 r=0 size=181 status=200 u=@rntpts:synapse.rntpts.de
19:17:47 INF ag=43 b=4/4/2000 c=room-list dev=ZKINVXQGHQ duration=34.516(34.126+0.384) l=2 p=0 q=1 r=20 size=164972 status=200 t=9208f76ee7bb4a11ad8b1901a8be2f31 u=@rntpts:synapse.rntpts.de
19:17:48 WRN failed to JSON-encode result error="HTTP 499 : write tcp 172.18.2.9:8008->172.18.2.4:59480: write: broken pipe"
19:17:48 INF client has resent this pos with different request data pos=1
19:17:48 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.122(0.118+0.002) l=3 p=1 q=2 r=44 size=214162 status=200 t=89359a9e7e9843a88ffe00480e6b84e3 u=@rntpts:synapse.rntpts.de
19:17:48 INF c=room-list dev=ZKINVXQGHQ duration=0.001 l=3 p=2 q=3 r=0 size=212 status=200 t=41f1e2e8d1fb4cfb9ab0fc6424179641 u=@rntpts:synapse.rntpts.de
19:17:48 INF c=room-list dev=ZKINVXQGHQ duration=0.596(0.001+0.000) l=3 p=3 q=4 r=0 size=169 status=200 t=b5c3ebc5573444bbb385fae60b0e222b u=@rntpts:synapse.rntpts.de
19:17:49 INF client has resent this pos with different request data pos=3
19:17:49 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.036(0.001+0.035) l=3 p=3 q=4 r=0 size=169 status=200 t=e3b1dfef594a43c392d3a61533403ab4 u=@rntpts:synapse.rntpts.de
19:17:49 INF c=room-list dev=ZKINVXQGHQ duration=0.001 l=3 p=4 q=5 r=1 size=2946 status=200 t=247a9f2b8b4b4fd2ae2fc446cfbe3433 u=@rntpts:synapse.rntpts.de
19:17:49 INF b=4/0/2000 c=room-list dev=ZKINVXQGHQ duration=1.757(0.001+0.748) l=3 p=1 q=2 r=44 size=3785 status=200 t=b6930cd8df7b434dbc54f52aa9c526cd u=@rntpts:synapse.rntpts.de
19:17:56 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=7.069(0.001+0.000) l=3 p=5 q=6 r=0 size=271 status=200 t=280a490e33da47498288ef49d4afadf9 u=@rntpts:synapse.rntpts.de
19:17:57 INF b=4/0/2000 c=encryption dev=ZKINVXQGHQ duration=10.191(0.001+0.000) p=2 q=3 r=0 size=146 status=200 u=@rntpts:synapse.rntpts.de
19:17:57 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=1.700(0.001+0.000) l=3 p=6 q=7 r=0 size=245 status=200 u=@rntpts:synapse.rntpts.de
19:18:08 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=10.732(0.001+0.000) l=3 p=7 q=8 r=0 size=227 status=200 u=@rntpts:synapse.rntpts.de
19:18:10 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=1.445(0.001+0.000) l=3 p=8 q=9 r=1 size=1136 status=200 u=@rntpts:synapse.rntpts.de
19:18:21 INF Poller: accumulated data device [events,changed,left,account]=[0,0,0,0] device_id=ZKINVXQGHQ rooms [timeline,state,typing,receipts,invites]=[2,0,4,2,0] user_id=@rntpts:synapse.rntpts.de
19:18:21 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=11.661(0.001+0.000) l=3 p=9 q=10 r=1 size=1021 status=200 u=@rntpts:synapse.rntpts.de
19:18:27 INF c=encryption dev=ZKINVXQGHQ duration=30.005(0.001+0.000) p=3 q=4 r=0 size=80 status=200 u=@rntpts:synapse.rntpts.de
19:18:41 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=19.196(0.001+0.000) l=3 p=10 q=11 r=0 size=340 status=200 u=@rntpts:synapse.rntpts.de
19:18:41 INF b=0/0/2000 c=encryption d=1 dev=ZKINVXQGHQ duration=14.154(0.001+0.000) p=4 q=5 r=0 size=318 status=200 u=@rntpts:synapse.rntpts.de
19:18:42 INF b=0/0/2000 c=encryption d=1 dev=ZKINVXQGHQ duration=0.938(0.001+0.000) p=5 q=6 r=0 size=457 status=200 u=@rntpts:synapse.rntpts.de
19:18:42 INF b=0/0/2000 c=encryption d=1 dev=ZKINVXQGHQ duration=0.118(0.002+0.000) p=6 q=7 r=0 size=279 status=200 u=@rntpts:synapse.rntpts.de
19:18:49 INF b=0/0/2000 c=encryption d=1 dev=ZKINVXQGHQ duration=7.276(0.001+0.000) p=7 q=8 r=0 size=455 status=200 u=@rntpts:synapse.rntpts.de
19:18:50 INF b=0/0/2000 c=encryption dev=ZKINVXQGHQ dl-c=1 duration=0.093(0.001+0.000) p=8 q=9 r=0 size=157 status=200 u=@rntpts:synapse.rntpts.de
19:18:50 INF b=0/0/2000 c=encryption d=1 dev=ZKINVXQGHQ duration=0.050(0.001+0.000) p=9 q=10 r=0 size=229 status=200 u=@rntpts:synapse.rntpts.de
19:18:50 INF b=0/0/2000 c=encryption d=1 dev=ZKINVXQGHQ duration=0.101(0.001+0.000) p=10 q=11 r=0 size=305 status=200 u=@rntpts:synapse.rntpts.de
19:18:50 WRN Client did not increment since token: possibly sending back duplicate to-device events! device=ZKINVXQGHQ initial=false last_sent=25 recv=23 user=@rntpts:synapse.rntpts.de
19:18:50 INF b=1/0/2000 c=encryption d=2 dev=ZKINVXQGHQ duration=0.009(0.001+0.005) p=11 q=12 r=0 size=582 status=200 u=@rntpts:synapse.rntpts.de
19:18:50 INF b=0/0/2000 c=encryption d=1 dev=ZKINVXQGHQ duration=0.060(0.001+0.000) p=12 q=13 r=0 size=311 status=200 u=@rntpts:synapse.rntpts.de
19:18:50 INF ToDeviceTable.Messages device=ZKINVXQGHQ msgid=b806da26-de71-4050-85de-d98890c36383 user=@rntpts:synapse.rntpts.de
19:18:50 INF ToDeviceTable.Messages device=ZKINVXQGHQ msgid=443197a5-a4b3-4c53-b9bd-026ea9ae317a user=@rntpts:synapse.rntpts.de
19:18:50 INF ToDeviceTable.Messages device=ZKINVXQGHQ msgid=23ab7f84-5823-4ce5-8cb3-44f540eb5742 user=@rntpts:synapse.rntpts.de
19:18:50 INF ToDeviceTable.Messages device=ZKINVXQGHQ msgid=3f91ad73-79db-4c55-9431-e5817f86d925 user=@rntpts:synapse.rntpts.de
19:18:50 INF b=0/0/2000 c=encryption d=4 dev=ZKINVXQGHQ duration=0.023(0.001+0.000) p=13 q=14 r=0 size=4325 status=200 u=@rntpts:synapse.rntpts.de
19:18:50 INF b=0/0/2000 c=encryption dev=ZKINVXQGHQ duration=0.005(0.001+0.005) p=14 q=15 r=0 size=145 status=200 u=@rntpts:synapse.rntpts.de
19:18:51 WRN Client did not increment since token: possibly sending back duplicate to-device events! device=ZKINVXQGHQ initial=false last_sent=33 recv=30 user=@rntpts:synapse.rntpts.de
19:18:51 INF b=1/0/2000 c=encryption d=3 dev=ZKINVXQGHQ duration=0.007(0.001+0.003) p=15 q=16 r=0 size=672 status=200 u=@rntpts:synapse.rntpts.de
19:19:03 INF Poller: accumulated data device [events,changed,left,account]=[16,2,0,0] device_id=ZKINVXQGHQ rooms [timeline,state,typing,receipts,invites]=[0,0,0,1,0] user_id=@rntpts:synapse.rntpts.de
19:19:08 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=27.435(0.001+0.000) l=3 p=11 q=12 r=1 size=1323 status=200 u=@rntpts:synapse.rntpts.de
19:19:08 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.157(0.001+0.000) l=3 p=12 q=13 r=0 size=327 status=200 u=@rntpts:synapse.rntpts.de
19:19:12 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=3.931(0.001+0.000) l=3 p=13 q=14 r=0 size=319 status=200 u=@rntpts:synapse.rntpts.de
19:19:21 INF c=encryption dev=ZKINVXQGHQ duration=30.007(0.001+0.000) p=16 q=17 r=0 size=82 status=200 u=@rntpts:synapse.rntpts.de
19:19:21 INF b=0/0/2000 c=encryption dev=ZKINVXQGHQ dl-c=1 duration=0.005(0.001+0.004) p=17 q=18 r=0 size=155 status=200 u=@rntpts:synapse.rntpts.de
19:19:21 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=8.491(0.001+0.000) l=3 p=14 q=15 r=0 size=336 status=200 u=@rntpts:synapse.rntpts.de
19:19:35 INF Poller: accumulated data device [events,changed,left,account]=[0,0,0,0] device_id=ZKINVXQGHQ rooms [timeline,state,typing,receipts,invites]=[1,0,0,4,0] user_id=@rntpts:synapse.rntpts.de
19:19:35 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=13.455(0.001+0.000) l=3 p=15 q=16 r=0 size=340 status=200 u=@rntpts:synapse.rntpts.de
19:19:51 INF c=encryption dev=ZKINVXQGHQ duration=30.006(0.001+0.000) p=18 q=19 r=0 size=82 status=200 u=@rntpts:synapse.rntpts.de
19:19:56 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=21.394(0.002+0.000) l=3 p=16 q=17 r=0 size=343 status=200 u=@rntpts:synapse.rntpts.de
19:20:04 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=8.139(0.001+0.000) l=3 p=17 q=18 r=0 size=338 status=200 u=@rntpts:synapse.rntpts.de
19:20:04 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.031(0.001+0.000) l=3 p=18 q=19 r=0 size=336 status=200 u=@rntpts:synapse.rntpts.de
19:20:04 INF b=2/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.002(0.001+0.000) l=3 p=19 q=20 r=0 size=513 status=200 u=@rntpts:synapse.rntpts.de
19:20:05 INF Poller: accumulated data device [events,changed,left,account]=[0,0,0,0] device_id=ZKINVXQGHQ rooms [timeline,state,typing,receipts,invites]=[0,0,1,4,0] user_id=@rntpts:synapse.rntpts.de
19:20:05 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.220(0.001+0.000) l=3 p=20 q=21 r=0 size=246 status=200 u=@rntpts:synapse.rntpts.de
19:20:05 INF b=1/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.003(0.001+0.000) l=3 p=21 q=22 r=0 size=336 status=200 u=@rntpts:synapse.rntpts.de
19:20:06 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=1.829(0.001+0.000) l=3 p=22 q=23 r=1 size=1318 status=200 u=@rntpts:synapse.rntpts.de
19:20:07 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.096(0.001+0.000) l=3 p=23 q=24 r=0 size=228 status=200 u=@rntpts:synapse.rntpts.de
19:20:07 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.323(0.001+0.000) l=3 p=24 q=25 r=0 size=246 status=200 u=@rntpts:synapse.rntpts.de
19:20:09 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=2.344(0.001+0.000) l=3 p=25 q=26 r=0 size=228 status=200 u=@rntpts:synapse.rntpts.de
19:20:11 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=1.292(0.001+0.000) l=3 p=26 q=27 r=1 size=1402 status=200 u=@rntpts:synapse.rntpts.de
19:20:21 INF c=encryption dev=ZKINVXQGHQ duration=30.007(0.001+0.000) p=19 q=20 r=0 size=82 status=200 u=@rntpts:synapse.rntpts.de
19:20:21 INF b=0/0/2000 c=encryption dev=ZKINVXQGHQ dl-c=1 duration=0.005(0.001+0.004) p=20 q=21 r=0 size=154 status=200 u=@rntpts:synapse.rntpts.de
19:20:41 INF Poller: accumulated data device [events,changed,left,account]=[0,1,0,0] device_id=ZKINVXQGHQ rooms [timeline,state,typing,receipts,invites]=[2,0,3,1,0] user_id=@rntpts:synapse.rntpts.de
19:20:41 INF c=room-list dev=ZKINVXQGHQ duration=30.003(0.001+0.000) l=3 p=27 q=28 r=0 size=126 status=200 u=@rntpts:synapse.rntpts.de
19:20:51 INF c=encryption dev=ZKINVXQGHQ duration=30.005(0.001+0.000) p=21 q=22 r=0 size=82 status=200 u=@rntpts:synapse.rntpts.de
19:20:55 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=13.992(0.001+0.000) l=3 p=28 q=29 r=0 size=330 status=200 u=@rntpts:synapse.rntpts.de
19:21:21 INF c=encryption dev=ZKINVXQGHQ duration=30.006(0.002+0.000) p=22 q=23 r=0 size=82 status=200 u=@rntpts:synapse.rntpts.de
19:21:25 INF Poller: accumulated data device [events,changed,left,account]=[0,0,0,0] device_id=ZKINVXQGHQ rooms [timeline,state,typing,receipts,invites]=[0,0,0,1,0] user_id=@rntpts:synapse.rntpts.de
19:21:25 INF c=room-list dev=ZKINVXQGHQ duration=30.003(0.001+0.000) l=3 p=29 q=30 r=0 size=126 status=200 u=@rntpts:synapse.rntpts.de
19:21:38 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=12.519(0.001+0.000) l=3 p=30 q=31 r=1 size=980 status=200 u=@rntpts:synapse.rntpts.de
19:21:38 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.038(0.001+0.000) l=3 p=31 q=32 r=0 size=327 status=200 u=@rntpts:synapse.rntpts.de
19:21:51 INF c=encryption dev=ZKINVXQGHQ duration=30.005(0.001+0.000) p=23 q=24 r=0 size=82 status=200 u=@rntpts:synapse.rntpts.de
19:22:04 INF Poller: accumulated data device [events,changed,left,account]=[0,0,0,0] device_id=ZKINVXQGHQ rooms [timeline,state,typing,receipts,invites]=[1,0,0,2,0] user_id=@rntpts:synapse.rntpts.de
19:22:04 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=26.534(0.001+0.000) l=3 p=32 q=33 r=0 size=336 status=200 u=@rntpts:synapse.rntpts.de
19:22:17 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=12.714(0.001+0.000) l=3 p=33 q=34 r=0 size=324 status=200 u=@rntpts:synapse.rntpts.de
19:22:21 INF c=encryption dev=ZKINVXQGHQ duration=30.011(0.007+0.000) p=24 q=25 r=0 size=82 status=200 u=@rntpts:synapse.rntpts.de
19:22:31 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=13.914(0.001+0.000) l=3 p=34 q=35 r=0 size=344 status=200 u=@rntpts:synapse.rntpts.de
19:22:41 INF Poller: accumulated data device [events,changed,left,account]=[0,0,0,0] device_id=ZKINVXQGHQ rooms [timeline,state,typing,receipts,invites]=[1,0,0,2,0] user_id=@rntpts:synapse.rntpts.de
19:22:41 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=10.001(0.001+0.000) l=3 p=35 q=36 r=1 size=949 status=200 u=@rntpts:synapse.rntpts.de
19:22:51 INF c=encryption dev=ZKINVXQGHQ duration=30.005(0.001+0.000) p=25 q=26 r=0 size=82 status=200 u=@rntpts:synapse.rntpts.de
19:23:11 INF Poller: accumulated data device [events,changed,left,account]=[0,0,0,0] device_id=ZKINVXQGHQ rooms [timeline,state,typing,receipts,invites]=[0,0,0,0,0] user_id=@rntpts:synapse.rntpts.de
19:23:11 INF c=room-list dev=ZKINVXQGHQ duration=30.004(0.001+0.000) l=3 p=36 q=37 r=0 size=126 status=200 u=@rntpts:synapse.rntpts.de
19:23:14 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=3.024(0.001+0.000) l=3 p=37 q=38 r=0 size=252 status=200 u=@rntpts:synapse.rntpts.de
19:23:14 INF b=1/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.002(0.001+0.000) l=3 p=38 q=39 r=0 size=341 status=200 u=@rntpts:synapse.rntpts.de
19:23:14 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.003(0.001+0.000) l=3 p=39 q=40 r=0 size=345 status=200 u=@rntpts:synapse.rntpts.de
19:23:14 INF ToDeviceTable.Messages device=ZKINVXQGHQ msgid=621134a0-76e2-418e-a493-858b4699d690 user=@rntpts:synapse.rntpts.de
19:23:14 INF b=0/0/2000 c=encryption d=1 dev=ZKINVXQGHQ duration=23.197(0.001+0.000) p=26 q=27 r=0 size=1677 status=200 u=@rntpts:synapse.rntpts.de
19:23:14 INF b=0/0/2000 c=encryption dev=ZKINVXQGHQ duration=0.005(0.001+0.005) p=27 q=28 r=0 size=145 status=200 u=@rntpts:synapse.rntpts.de
19:23:15 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.194(0.001+0.000) l=3 p=40 q=41 r=0 size=232 status=200 u=@rntpts:synapse.rntpts.de
19:23:15 INF b=0/0/2000 c=encryption dev=ZKINVXQGHQ duration=0.191(0.001+0.000) p=28 q=29 r=0 size=145 status=200 u=@rntpts:synapse.rntpts.de
19:23:15 INF b=0/0/2000 c=encryption dev=ZKINVXQGHQ duration=0.314(0.001+0.000) p=29 q=30 r=1 size=166 status=200 u=@rntpts:synapse.rntpts.de
19:23:15 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.360(0.001+0.000) l=3 p=41 q=42 r=1 size=1711 status=200 u=@rntpts:synapse.rntpts.de
19:23:15 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.002(0.001+0.001) l=3 p=42 q=43 r=0 size=168 status=200 u=@rntpts:synapse.rntpts.de
19:23:16 INF Received connection from unknown access token, querying with homeserver
19:23:16 WRN failed to get or create Conn error="HTTP 401 : /whoami returned HTTP 401"
19:23:17 INF c= duration=1.006 size=76 status=401
19:23:34 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=19.190(0.001+0.000) l=3 p=43 q=44 r=0 size=336 status=200 u=@rntpts:synapse.rntpts.de
19:23:35 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.575(0.001+0.000) l=3 p=44 q=45 r=0 size=252 status=200 u=@rntpts:synapse.rntpts.de
19:23:41 INF c=encryption dev=ZKINVXQGHQ duration=25.546(0.001+0.000) p=30 q=31 r=0 size=82 status=200 u=@rntpts:synapse.rntpts.de
19:23:41 INF c=room-list dev=ZKINVXQGHQ duration=5.353(0.001+0.000) l=3 p=45 q=46 r=0 size=126 status=200 u=@rntpts:synapse.rntpts.de
19:23:44 INF Poller: accumulated data device [events,changed,left,account]=[1,0,0,0] device_id=ZKINVXQGHQ rooms [timeline,state,typing,receipts,invites]=[1,0,4,3,0] user_id=@rntpts:synapse.rntpts.de
19:24:15 INF Poller: accumulated data device [events,changed,left,account]=[0,0,1,0] device_id=ZKINVXQGHQ rooms [timeline,state,typing,receipts,invites]=[2,0,0,1,0] user_id=@rntpts:synapse.rntpts.de
19:24:31 INF Received connection from unknown access token, querying with homeserver
19:24:31 WRN failed to get or create Conn error="HTTP 401 : /whoami returned HTTP 401"
19:24:32 INF c= duration=1.009 size=76 status=401
19:24:47 INF Poller: accumulated data device [events,changed,left,account]=[0,0,0,0] device_id=ZKINVXQGHQ rooms [timeline,state,typing,receipts,invites]=[1,0,4,2,0] user_id=@rntpts:synapse.rntpts.de
19:25:17 INF Poller: accumulated data device [events,changed,left,account]=[0,0,0,0] device_id=ZKINVXQGHQ rooms [timeline,state,typing,receipts,invites]=[0,0,0,0,0] user_id=@rntpts:synapse.rntpts.de
19:25:43 INF client has resent this pos with different request data pos=45
19:25:43 INF b=14/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.010(0.001+0.002) l=3 p=45 q=46 r=0 size=126 status=200 t=4e64dc10be8e445a88180cf97b7d8881 u=@rntpts:synapse.rntpts.de
19:25:43 INF c=encryption dev=ZKINVXQGHQ duration=0.012 p=30 q=31 r=0 size=82 status=200 u=@rntpts:synapse.rntpts.de
19:25:43 INF b=14/0/2000 c=encryption dev=ZKINVXQGHQ dl-l=1 duration=0.012(0.001+0.000) p=31 q=32 r=1 size=232 status=200 u=@rntpts:synapse.rntpts.de
19:25:43 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.234(0.002+0.232) l=3 p=46 q=47 r=2 size=4042 status=200 t=053711c302234b27b6cceb18fccca233 u=@rntpts:synapse.rntpts.de
19:25:43 INF c=room-list dev=ZKINVXQGHQ duration=0.002 l=3 p=47 q=48 r=29 size=112121 status=200 t=3e87c7d250f34caa8fb60269de5d913c u=@rntpts:synapse.rntpts.de
19:25:49 INF c=room-list dev=ZKINVXQGHQ duration=5.898(0.001+0.000) l=3 p=48 q=49 r=0 size=170 status=200 t=1159232d67b94b84a1498953b0fb44ce u=@rntpts:synapse.rntpts.de
19:25:49 INF client has resent this pos with different request data pos=48
19:25:49 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.015(0.001+0.013) l=3 p=48 q=49 r=0 size=170 status=200 sub=1 t=cd14bce195864eaab8c883a2b357a919 u=@rntpts:synapse.rntpts.de
19:25:49 INF c=room-list dev=ZKINVXQGHQ duration=0.001 l=3 p=49 q=50 r=1 size=4156 status=200 sub=1 t=3d0838c828c04db98c5bf6f1bd50cdb6 u=@rntpts:synapse.rntpts.de
19:25:49 INF Poller: accumulated data device [events,changed,left,account]=[0,0,0,0] device_id=ZKINVXQGHQ rooms [timeline,state,typing,receipts,invites]=[0,0,0,1,0] user_id=@rntpts:synapse.rntpts.de
19:25:50 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.032(0.001+0.000) l=3 p=50 q=51 r=0 size=387 status=200 sub=1 t=31c0f199002e47759fc2122018c60e74 u=@rntpts:synapse.rntpts.de
19:25:50 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.057(0.001+0.000) l=3 p=51 q=52 r=0 size=330 status=200 u=@rntpts:synapse.rntpts.de
19:25:50 INF b=0/0/2000 c=encryption dev=ZKINVXQGHQ duration=6.507(0.001+0.000) p=32 q=33 r=1 size=166 status=200 u=@rntpts:synapse.rntpts.de
19:25:50 INF b=1/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.005(0.001+0.000) l=3 p=52 q=53 r=1 size=543 status=200 u=@rntpts:synapse.rntpts.de
19:25:57 INF c=encryption dev=ZKINVXQGHQ duration=7.396(0.001+0.000) p=33 q=34 r=0 size=82 status=200 u=@rntpts:synapse.rntpts.de
19:25:57 INF c=room-list dev=ZKINVXQGHQ duration=7.379(0.001+0.000) l=3 p=53 q=54 r=0 size=126 status=200 u=@rntpts:synapse.rntpts.de
19:25:58 INF created new connection conn=encryption device=ZKINVXQGHQ user=@rntpts:synapse.rntpts.de
19:25:58 INF created new connection conn=room-list device=ZKINVXQGHQ user=@rntpts:synapse.rntpts.de
19:25:58 INF b=0/0/2000 c=encryption dev=ZKINVXQGHQ duration=0.009(0.006+0.004) p=0 q=1 r=0 size=245 status=200 t=a4c3522f75f74a92b8a4d47dfcd5113d u=@rntpts:synapse.rntpts.de
19:25:59 INF ag=43 b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.316(0.005+0.309) l=2 p=0 q=1 r=20 size=165136 status=200 t=d9b8c8cfa06049c7a4bf800280cf4c4d u=@rntpts:synapse.rntpts.de
19:25:59 INF client has resent this pos with different request data pos=1
19:25:59 WRN failed to JSON-encode result error="HTTP 499 : write tcp 172.18.2.9:8008->172.18.2.4:54068: write: broken pipe"
19:25:59 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.244(0.241+0.001) l=3 p=1 q=2 r=44 size=219318 status=200 t=c7b7e945a7ed45bca2ba47cd63a426e8 u=@rntpts:synapse.rntpts.de
19:25:59 INF c=room-list dev=ZKINVXQGHQ duration=0.001 l=3 p=2 q=3 r=0 size=212 status=200 t=55f71e05f9164b0a84aae95f45569316 u=@rntpts:synapse.rntpts.de
19:26:00 INF c=room-list dev=ZKINVXQGHQ duration=0.339(0.001+0.000) l=3 p=3 q=4 r=0 size=169 status=200 t=b577b1b4b67e41c287eacd9654a450f9 u=@rntpts:synapse.rntpts.de
19:26:00 INF client has resent this pos with different request data pos=3
19:26:00 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=0.014(0.001+0.012) l=3 p=3 q=4 r=0 size=169 status=200 sub=1 t=60481b71f4f94683a4c38e25ca52c885 u=@rntpts:synapse.rntpts.de
19:26:00 INF c=room-list dev=ZKINVXQGHQ duration=0.001 l=3 p=4 q=5 r=1 size=4155 status=200 sub=1 t=6559a74b8cb34fcda84dfef64c540e3a u=@rntpts:synapse.rntpts.de
19:26:00 INF b=0/0/2000 c=room-list dev=ZKINVXQGHQ duration=1.501(0.001+0.497) l=3 p=1 q=2 r=44 size=3785 status=200 t=6838993dcb664c2a9a1931621f10c55e u=@rntpts:synapse.rntpts.de
19:26:10 INF c=room-list dev=ZKINVXQGHQ duration=10.022(0.001+0.000) l=3 p=5 q=6 r=0 size=169 status=200 sub=1 t=3b943a7b608f4ec38756821f94931d41 u=@rntpts:synapse.rntpts.de
19:26:10 INF c=encryption dev=ZKINVXQGHQ duration=11.623(0.001+0.000) p=1 q=2 r=0 size=81 status=200 u=@rntpts:synapse.rntpts.de
19:26:10 WRN poller: access token has been invalidated, terminating loop device_id=ZKINVXQGHQ user_id=@rntpts:synapse.rntpts.de
19:26:10 INF Poller: accumulated data device [events,changed,left,account]=[0,1,0,0] device_id=ZKINVXQGHQ rooms [timeline,state,typing,receipts,invites]=[0,0,0,2,0] user_id=@rntpts:synapse.rntpts.de
19:26:10 INF closing connection due to expired TTL in cache conn=@rntpts:synapse.rntpts.de|ZKINVXQGHQ|room-list
19:26:10 INF closing connection due to expired TTL in cache conn=@rntpts:synapse.rntpts.de|ZKINVXQGHQ|encryption

marwing avatar Mar 11 '24 20:03 marwing

Had exactly the same issue on my iPad after switching from SS to SSS (hence logged out).

Reboot solves the issue. Version 1.7.4(120)

jacotec avatar Sep 04 '24 21:09 jacotec

I can no longer reproduce this with proxy or SSS on 1.8.1 (123) on iOS 18.0. I suspect #3273 missed closing this issue?

marwing avatar Sep 17 '24 10:09 marwing

Ooops, yes my bad. Thanks for following up!

pixlwave avatar Sep 17 '24 10:09 pixlwave