Under observation: key exchange not successful if new client is verified by timmy.
sometimes the verification with timmy is not completely done.
Steps to reproduce:
- Login with user on Timmy
- Login with same user in a new client (e.g. element)
- verify the new client via Timmy
Current result: verification is shown as successful but old messages of the user can not be decrypted in new client
Expected result: verification is shown as successful and all old messages of the user can be decrypted in new client.
Log Ausschnitt: (Zum Erweitern klicken)
09:45:04.624 [DefaultDispatcher-worker-31] DEBUG n.f.t.c.c.SyncApiClient - received sync response after about 42.056900ms with token s2212383_140456512_6391_5533679_721925_1084_312950_17156345_0_67
09:45:04.667 [DefaultDispatcher-worker-16] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - handle incoming room key requests
09:45:04.667 [DefaultDispatcher-worker-16] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - handle incoming room key requests
09:45:04.667 [DefaultDispatcher-worker-16] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - handle incoming room key requests
09:45:04.667 [DefaultDispatcher-worker-16] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - handle incoming room key requests
09:45:04.667 [DefaultDispatcher-worker-16] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - handle incoming room key requests
09:45:04.667 [DefaultDispatcher-worker-16] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - handle incoming room key requests
09:45:04.667 [DefaultDispatcher-worker-16] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - handle incoming room key requests
09:45:04.667 [DefaultDispatcher-worker-16] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - handle incoming room key requests
09:45:04.667 [DefaultDispatcher-worker-16] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - handle incoming room key requests
09:45:04.667 [DefaultDispatcher-worker-16] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - handle incoming room key requests
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.s.KeyStore - wait for outdated keys of @ma.uh:imbitbu.de
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - process incoming room key request (requestId=m1706863502706.257, isVerified=true)
09:45:04.667 [DefaultDispatcher-worker-12] INFO n.f.t.c.k.IncomingRoomKeyRequestEventHandler - got a room key request (RoomKeyRequestEventContent(action=REQUEST, requestingDeviceId=XMITCAUYBM, requestId=m1706863502706.257, body=RequestedKeyInfo(roomId=!RvSCtYSdJfhJStNHdN:imbitbu.de, sessionId=uhSeLwgs5T0tCuegzlhEgdAkU1l6JSxrw2PUWx6/g48, algorithm=Megolm))), but did not found a matching room key
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.s.KeyStore - wait for outdated keys of @ma.uh:imbitbu.de
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - process incoming room key request (requestId=m1706863502728.258, isVerified=true)
09:45:04.667 [DefaultDispatcher-worker-12] INFO n.f.t.c.k.IncomingRoomKeyRequestEventHandler - got a room key request (RoomKeyRequestEventContent(action=REQUEST, requestingDeviceId=XMITCAUYBM, requestId=m1706863502728.258, body=RequestedKeyInfo(roomId=!RvSCtYSdJfhJStNHdN:imbitbu.de, sessionId=0pgUKSIfNUyhvBMtTbHlXyur8roFV1i7lp+fflU6Zow, algorithm=Megolm))), but did not found a matching room key
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.s.KeyStore - wait for outdated keys of @ma.uh:imbitbu.de
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - process incoming room key request (requestId=m1706863502731.259, isVerified=true)
09:45:04.667 [DefaultDispatcher-worker-12] INFO n.f.t.c.k.IncomingRoomKeyRequestEventHandler - got a room key request (RoomKeyRequestEventContent(action=REQUEST, requestingDeviceId=XMITCAUYBM, requestId=m1706863502731.259, body=RequestedKeyInfo(roomId=!RvSCtYSdJfhJStNHdN:imbitbu.de, sessionId=CdO6+q/3ELAuVVxnOu2K7rZk75p4y+p7/UrrjS0/o5I, algorithm=Megolm))), but did not found a matching room key
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.s.KeyStore - wait for outdated keys of @ma.uh:imbitbu.de
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - process incoming room key request (requestId=m1706863502732.261, isVerified=true)
09:45:04.667 [DefaultDispatcher-worker-12] INFO n.f.t.c.k.IncomingRoomKeyRequestEventHandler - got a room key request (RoomKeyRequestEventContent(action=REQUEST, requestingDeviceId=XMITCAUYBM, requestId=m1706863502732.261, body=RequestedKeyInfo(roomId=!RvSCtYSdJfhJStNHdN:imbitbu.de, sessionId=+L8q+OcQVMg5PKmRSMLSOvy1duuEs5vfqOHpigfkuQA, algorithm=Megolm))), but did not found a matching room key
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.s.KeyStore - wait for outdated keys of @ma.uh:imbitbu.de
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - process incoming room key request (requestId=m1706863502734.262, isVerified=true)
09:45:04.667 [DefaultDispatcher-worker-12] INFO n.f.t.c.k.IncomingRoomKeyRequestEventHandler - got a room key request (RoomKeyRequestEventContent(action=REQUEST, requestingDeviceId=XMITCAUYBM, requestId=m1706863502734.262, body=RequestedKeyInfo(roomId=!RvSCtYSdJfhJStNHdN:imbitbu.de, sessionId=dktpQtwqvQZitO92gWf1zrq20mkhyzGZ8Fbn8cENl8o, algorithm=Megolm))), but did not found a matching room key
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.s.KeyStore - wait for outdated keys of @ma.uh:imbitbu.de
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - process incoming room key request (requestId=m1706863502741.265, isVerified=true)
09:45:04.667 [DefaultDispatcher-worker-12] INFO n.f.t.c.k.IncomingRoomKeyRequestEventHandler - got a room key request (RoomKeyRequestEventContent(action=REQUEST, requestingDeviceId=XMITCAUYBM, requestId=m1706863502741.265, body=RequestedKeyInfo(roomId=!RvSCtYSdJfhJStNHdN:imbitbu.de, sessionId=9kU0Zqt3YRK0+Z6SYmNKBNsqZTvqesvLdN1TWxER5SI, algorithm=Megolm))), but did not found a matching room key
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.s.KeyStore - wait for outdated keys of @ma.uh:imbitbu.de
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - process incoming room key request (requestId=m1706863502741.266, isVerified=true)
09:45:04.667 [DefaultDispatcher-worker-12] INFO n.f.t.c.k.IncomingRoomKeyRequestEventHandler - got a room key request (RoomKeyRequestEventContent(action=REQUEST, requestingDeviceId=XMITCAUYBM, requestId=m1706863502741.266, body=RequestedKeyInfo(roomId=!RvSCtYSdJfhJStNHdN:imbitbu.de, sessionId=PdO2Jz58Otx9nUbfFgyMN7Qg1K8GGeCdHBzxJ+ySvUU, algorithm=Megolm))), but did not found a matching room key
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.s.KeyStore - wait for outdated keys of @ma.uh:imbitbu.de
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - process incoming room key request (requestId=m1706863502746.268, isVerified=true)
09:45:04.667 [DefaultDispatcher-worker-12] INFO n.f.t.c.k.IncomingRoomKeyRequestEventHandler - got a room key request (RoomKeyRequestEventContent(action=REQUEST, requestingDeviceId=XMITCAUYBM, requestId=m1706863502746.268, body=RequestedKeyInfo(roomId=!RvSCtYSdJfhJStNHdN:imbitbu.de, sessionId=6D+XPRU73iIFm+WBngQ6Q5vis11lHO7j0Dl7dbr5XMY, algorithm=Megolm))), but did not found a matching room key
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.s.KeyStore - wait for outdated keys of @ma.uh:imbitbu.de
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - process incoming room key request (requestId=m1706863502746.270, isVerified=true)
09:45:04.667 [DefaultDispatcher-worker-12] INFO n.f.t.c.k.IncomingRoomKeyRequestEventHandler - got a room key request (RoomKeyRequestEventContent(action=REQUEST, requestingDeviceId=XMITCAUYBM, requestId=m1706863502746.270, body=RequestedKeyInfo(roomId=!RvSCtYSdJfhJStNHdN:imbitbu.de, sessionId=+Z4NvYcYsd/n7KCJN7uMUwkWnuxHLsP1s3ryxlenncM, algorithm=Megolm))), but did not found a matching room key
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.s.KeyStore - wait for outdated keys of @ma.uh:imbitbu.de
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - process incoming room key request (requestId=m1706863502752.273, isVerified=true)
09:45:04.667 [DefaultDispatcher-worker-12] INFO n.f.t.c.k.IncomingRoomKeyRequestEventHandler - got a room key request (RoomKeyRequestEventContent(action=REQUEST, requestingDeviceId=XMITCAUYBM, requestId=m1706863502752.273, body=RequestedKeyInfo(roomId=!RvSCtYSdJfhJStNHdN:imbitbu.de, sessionId=9Af3HtlqvCilOiF+z9WTXOc/aHJh4mbI976x+kJavws, algorithm=Megolm))), but did not found a matching room key
09:45:04.667 [DefaultDispatcher-worker-12] DEBUG n.f.t.c.c.SyncApiClient - processed sync response in about 43.094900ms with token s2212383_140456512_6391_5533679_721925_1084_312950_17156345_0_67
09:45:06.719 [DefaultDispatcher-worker-4] DEBUG n.f.t.c.c.SyncApiClient - received sync response after about 36.949300ms with token s2212383_140456514_6391_5533679_721926_1084_312960_17156345_0_67
09:45:06.736 [DefaultDispatcher-worker-29] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - handle incoming room key requests
09:45:06.736 [DefaultDispatcher-worker-29] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - handle incoming room key requests
09:45:06.736 [DefaultDispatcher-worker-29] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - handle incoming room key requests
09:45:06.736 [DefaultDispatcher-worker-29] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - handle incoming room key requests
09:45:06.736 [DefaultDispatcher-worker-28] DEBUG n.f.t.c.s.KeyStore - wait for outdated keys of @ma.uh:imbitbu.de
09:45:06.736 [DefaultDispatcher-worker-28] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - process incoming room key request (requestId=m1706863502752.274, isVerified=true)
09:45:06.736 [DefaultDispatcher-worker-28] INFO n.f.t.c.k.IncomingRoomKeyRequestEventHandler - got a room key request (RoomKeyRequestEventContent(action=REQUEST, requestingDeviceId=XMITCAUYBM, requestId=m1706863502752.274, body=RequestedKeyInfo(roomId=!RvSCtYSdJfhJStNHdN:imbitbu.de, sessionId=kjcDtO8eaMpx1AHmkgH0yP3k2pLl9DQDiQ+6iXhzBcQ, algorithm=Megolm))), but did not found a matching room key
09:45:06.736 [DefaultDispatcher-worker-28] DEBUG n.f.t.c.s.KeyStore - wait for outdated keys of @ma.uh:imbitbu.de
09:45:06.736 [DefaultDispatcher-worker-28] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - process incoming room key request (requestId=m1706863502752.275, isVerified=true)
09:45:06.736 [DefaultDispatcher-worker-28] INFO n.f.t.c.k.IncomingRoomKeyRequestEventHandler - got a room key request (RoomKeyRequestEventContent(action=REQUEST, requestingDeviceId=XMITCAUYBM, requestId=m1706863502752.275, body=RequestedKeyInfo(roomId=!RvSCtYSdJfhJStNHdN:imbitbu.de, sessionId=aZToGgD/hU7nNxDR3MnsHnTGM9DFyT1889B9TnGI1ko, algorithm=Megolm))), but did not found a matching room key
09:45:06.736 [DefaultDispatcher-worker-28] DEBUG n.f.t.c.s.KeyStore - wait for outdated keys of @ma.uh:imbitbu.de
09:45:06.736 [DefaultDispatcher-worker-28] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - process incoming room key request (requestId=m1706863502761.278, isVerified=true)
09:45:06.736 [DefaultDispatcher-worker-28] INFO n.f.t.c.k.IncomingRoomKeyRequestEventHandler - got a room key request (RoomKeyRequestEventContent(action=REQUEST, requestingDeviceId=XMITCAUYBM, requestId=m1706863502761.278, body=RequestedKeyInfo(roomId=!RvSCtYSdJfhJStNHdN:imbitbu.de, sessionId=7TUHimJ6U8FuAG7FMpVEfy+1K17+MdBXzPs0Mf5PC6g, algorithm=Megolm))), but did not found a matching room key
09:45:06.736 [DefaultDispatcher-worker-28] DEBUG n.f.t.c.s.KeyStore - wait for outdated keys of @ma.uh:imbitbu.de
09:45:06.736 [DefaultDispatcher-worker-28] DEBUG n.f.t.c.k.IncomingRoomKeyRequestEventHandler - process incoming room key request (requestId=m1706863502761.279, isVerified=true)
09:45:06.736 [DefaultDispatcher-worker-28] INFO n.f.t.c.k.IncomingRoomKeyRequestEventHandler - got a room key request (RoomKeyRequestEventContent(action=REQUEST, requestingDeviceId=XMITCAUYBM, requestId=m1706863502761.279, body=RequestedKeyInfo(roomId=!RvSCtYSdJfhJStNHdN:imbitbu.de, sessionId=UFu2D38YwhxhtDyD/s+UiZW3u7wOPec6z64F9QvCKg8, algorithm=Megolm))), but did not found a matching room key
09:45:06.736 [DefaultDispatcher-worker-28] DEBUG n.f.t.c.c.SyncApiClient - processed sync response in about 16.455900ms with token s2212383_140456514_6391_5533679_721926_1084_312960_17156345_0_67