nheko
nheko copied to clipboard
Published
20 hours ago •
mujx
mujx
Only single message could be delivered
System:
- Nheko version:
0.5.3 - Installation method:
λ dnf info nheko 2>/dev/null
Last metadata expiration check: 0:00:15 ago on Wed 22 Aug 2018 02:27:59 AM MSK.
Installed Packages
Name : nheko
Version : 0.5.3
Release : 2.fc28
Arch : x86_64
Size : 8.0 M
Source : nheko-0.5.3-2.fc28.src.rpm
Repo : @System
From repo : updates
Summary : Desktop client for the Matrix protocol
URL : https://github.com/mujx/nheko
License : GPLv3+ and ASL 2.0 and CC-BY
Description : The motivation behind the project is to provide a native desktop app
: for Matrix that feels more like a mainstream chat app.
- Operating System: Fedora Workstation 28
- Desktop Environment: i3wm
Actual behavior
Second message doesn't even get a sending icon. After that chat is dead, I also won't receive any next message.
Expected behavior
Second message is delivered
Steps to reproduce
- Send one message;
- Then try to send another.
Logs
[2018-08-22 02:17:00.846] [db] [error] saving sync response: mdb_put: MDB_MAP_FULL: Environment mapsize limit reached
Thanks for the very detailed bug report!
This seems like the lmdb is full and it can't receive the next sync response.
It will need a way to automatically remove old saved messages which I assume occupy most space.
@mujx 256MiB is the limit?
λ pwd && ls | xargs -i du -h {}
/home/uc/.cache/nheko/nheko/40756e636c656368753a6d61747269782e6f7267
256M data.mdb
4.0K lock.mdb
I'm not surprised since I have more than 150 rooms.
@unclechu Yes, that's the limit as defined below https://github.com/mujx/nheko/blob/199a4eaf517d672ad40cd094894c52d3c7e046c1/src/Cache.cpp#L135-L138
@mujx On current nightly release of 9f43ff876a8690c6f2a41ef0187ea783bf72a122 I still have this issue, but error message is different:
[2018-08-26 16:51:59.772] [db] [error] lmdb is full: mdb_put: MDB_MAP_FULL: Environment mapsize limit reached
[2018-08-26 16:51:59.774] [db] [info] [%SOME_INTERNAL_ROOM_ID%] message count: 174
[2018-08-26 16:51:59.776] [db] [error] failed to delete old messages: mdb_cursor_del: MDB_MAP_FULL: Environment mapsize limit reached
On nightly release 183975be1aeef9965a179eb1159d66e818b00ddd now I can send regular unencrypted messages but I can send only single message to an E2EE room, this particular bug with E2EE room have been appeared even before this issue.
Testing new created E2EE room:
[2018-08-29 19:00:27.493] [ui] [warning] updateUnreadMessageCount: unknown room_id !CfNzrVthKynLVbqEAY:matrix.org
type not found: {
"content": {
"guest_access": "can_join"
},
"event_id": "$153555841535657zizct:matrix.org",
"origin_server_ts": 1535558415736,
"sender": "@unclechu:matrix.org",
"state_key": "",
"type": "m.room.guest_access",
"unsigned": {
"age": 15380
}
}
type not found: {
"content": {
"avatar_url": "",
"displayname": "efie (IRC)",
"is_direct": false,
"membership": "join"
},
"event_id": "$15355584111100677EzIOA:matrix.org",
"origin_server_ts": 1535558411673,
"sender": "@freenode_efie:matrix.org",
"state_key": "@freenode_efie:matrix.org",
"type": "m.room.member",
"unsigned": {
"age": 19443
}
}
type not found: {
"content": {
"creator": "@unclechu:matrix.org",
"m.federate": true
},
"event_id": "$153555841235652OhfJs:matrix.org",
"origin_server_ts": 1535558412383,
"room_id": "!CfNzrVthKynLVbqEAY:matrix.org",
"sender": "@unclechu:matrix.org",
"state_key": "",
"type": "m.room.create",
"unsigned": {
"age": 30860
}
}
type not found: {
"content": {
"avatar_url": "",
"displayname": "freimatz3 (IRC)",
"is_direct": false,
"membership": "join"
},
"event_id": "$15355584471101152KymEo:matrix.org",
"origin_server_ts": 1535558447557,
"sender": "@freenode_freimatz3:matrix.org",
"state_key": "@freenode_freimatz3:matrix.org",
"type": "m.room.member",
"unsigned": {
"age": 13507,
"prev_sender": "@freenode_freimatz3:matrix.org",
"replaces_state": "$1535521687758427jLNRB:matrix.org"
}
}
type not found: {
"content": {
"avatar_url": "",
"displayname": "",
"is_direct": false,
"membership": "leave"
},
"event_id": "$15355584531101252UCsrI:matrix.org",
"origin_server_ts": 1535558453903,
"sender": "@freenode_crose:matrix.org",
"state_key": "@freenode_crose:matrix.org",
"type": "m.room.member",
"unsigned": {
"age": 12764,
"prev_sender": "@freenode_crose:matrix.org",
"replaces_state": "$1535549754992113FRlQQ:matrix.org"
}
}
[2018-08-29 19:01:13.484] [net] [info] enabled encryption on room (!CfNzrVthKynLVbqEAY:matrix.org)
[2018-08-29 19:01:16.908] [ui] [info] [wGEEPmTSum7l9dqOY6s9RnnUGcpSlDcZ] sending next queued message
[2018-08-29 19:01:17.575] [ui] [info] [wGEEPmTSum7l9dqOY6s9RnnUGcpSlDcZ] message was received by the server
[2018-08-29 19:01:18.597] [db] [info] mark room !CfNzrVthKynLVbqEAY:matrix.org as encrypted
type not found: {
"content": {
"algorithm": "m.megolm.v1.aes-sha2"
},
"event_id": "$1535558473400516fIJXR:matrix.org",
"origin_server_ts": 1535558473286,
"sender": "@unclechu:matrix.org",
"state_key": "",
"type": "m.room.encryption",
"unsigned": {
"age": 4793
}
}
[2018-08-29 19:01:19.833] [ui] [info] [wGEEPmTSum7l9dqOY6s9RnnUGcpSlDcZ] removed message with sync
[2018-08-29 19:01:21.126] [ui] [info] [ZoU9sqpKVAvCHfuVgiIXvz46rFd9MnLI] sending next queued message
[2018-08-29 19:01:21.126] [ui] [info] [ZoU9sqpKVAvCHfuVgiIXvz46rFd9MnLI] sending encrypted event
[2018-08-29 19:01:21.127] [ui] [info] creating new outbound megolm session
[2018-08-29 19:01:21.150] [ui] [info] retrieved 1 members for !CfNzrVthKynLVbqEAY:matrix.org
[2018-08-29 19:01:21.706] [net] [info] CCPZLYDIWF
[2018-08-29 19:01:21.706] [net] [info] curve25519 7xDsPNIdHMnIM8I24Uer+gRUHinn+Zc/bLKwiBLwalA
[2018-08-29 19:01:21.706] [net] [info] ed25519 6xlDCYQH86PxhDJFZPk/bnxAG8liS1f3rpLJpzQQI6Q
[2018-08-29 19:01:21.706] [net] [info] CZHNCGIUIW
[2018-08-29 19:01:21.706] [net] [info] curve25519 ttphBPXpykpTzidIxLPCI+jWz4FHtVH/IdChAw92QTY
[2018-08-29 19:01:21.706] [net] [info] ed25519 nBJuoKatw2TlJQIftqdG87TdLwOieTeLckmuaOQRm/0
[2018-08-29 19:01:21.706] [net] [info] WMFYKBCROZ
[2018-08-29 19:01:21.706] [net] [info] curve25519 WHN1nQYmTkhzJAt4G6AnpHI613wybH8lxnkkUMdsIRM
[2018-08-29 19:01:21.706] [net] [info] ed25519 LBeAnYTohQkjSrsXssKvbxj5rYYkleNV40vM6SDS8jk
[2018-08-29 19:01:21.706] [net] [info] sending claim request for user @unclechu:matrix.org with 3 devices
[2018-08-29 19:01:22.264] [net] [info] claimed keys for @unclechu:matrix.org
[2018-08-29 19:01:22.268] [net] [info] CCPZLYDIWF :
{
"signed_curve25519:AAAAHw": {
"key": "oNp2HO49rNn4N8JU93N+IfEYd3XeeI9doWWXCi4mvzw",
"signatures": {
"@unclechu:matrix.org": {
"ed25519:CCPZLYDIWF": "mwAWeAvrOwhZsL3HolGn+OitvL9nz5C3Np4aD+F8mBXKWfJiCzIgboXoCMF1L3QS04cisUDcp4aksHAXd8FsAw"
}
}
}
}
[2018-08-29 19:01:22.279] [net] [info] CZHNCGIUIW :
{
"signed_curve25519:AAAAHA": {
"key": "8ikM9W2VAV2tPtFcOPziRdO0LvGZ7LR6mvmmCSt5F1M",
"signatures": {
"@unclechu:matrix.org": {
"ed25519:CZHNCGIUIW": "H2PadnlNr4oy6aGgIa3qHmbdSARp2zpoliRI7LHRFlAJVXetyTeNYwd0m5kTrdDfx269nHY3iDGDF2CQwoomBw"
}
}
}
}
[2018-08-29 19:01:22.286] [net] [info] WMFYKBCROZ :
{
"signed_curve25519:AAAARA": {
"key": "JRbVjgAqRSRDyJ4HE0VGyQBmYKh/sob7Feavgggd40s",
"signatures": {
"@unclechu:matrix.org": {
"ed25519:WMFYKBCROZ": "Qb/W9YD3UfS+Xr6AIrmtXLufoo7Hsr1QsqQI73kQam9KJFnCjYd1PINeZt4icFFEedeOhxuBkMqpGVRwDR3hAA"
}
}
}
}
[2018-08-29 19:01:22.293] [net] [info] send_to_device: @unclechu:matrix.org
[2018-08-29 19:01:22.739] [crypto] [info] next message_index 1
[2018-08-29 19:01:23.308] [crypto] [info] received 1 to_device messages
[2018-08-29 19:01:23.308] [crypto] [info] sender : @unclechu:matrix.org
[2018-08-29 19:01:23.308] [crypto] [info] sender_key: ttphBPXpykpTzidIxLPCI+jWz4FHtVH/IdChAw92QTY
[2018-08-29 19:01:23.308] [crypto] [info] type: OLM_PRE_KEY
[2018-08-29 19:01:23.308] [crypto] [info] attempt to decrypt message with 11 known session_ids
[2018-08-29 19:01:23.327] [crypto] [info] failed to decrypt olm message (0, ttphBPXpykpTzidIxLPCI+jWz4FHtVH/IdChAw92QTY) with 0Oay7YkHavr79a6b6tqJ21z+cs1BMTIy6KyUFMZ94bc: olm_decrypt: BAD_MESSAGE_MAC
[2018-08-29 19:01:23.328] [crypto] [info] failed to decrypt olm message (0, ttphBPXpykpTzidIxLPCI+jWz4FHtVH/IdChAw92QTY) with 2WnuB6lX0DTRN1ZPxYWw44/WbMMbYAOvYPoyqH9r60c: olm_decrypt: BAD_MESSAGE_MAC
[2018-08-29 19:01:23.329] [crypto] [info] failed to decrypt olm message (0, ttphBPXpykpTzidIxLPCI+jWz4FHtVH/IdChAw92QTY) with 7+P4AunZXGaA79B5xhFYssKBB6W/W5Mo7Q/g/3t3EBk: olm_decrypt: BAD_MESSAGE_MAC
[2018-08-29 19:01:23.330] [crypto] [info] failed to decrypt olm message (0, ttphBPXpykpTzidIxLPCI+jWz4FHtVH/IdChAw92QTY) with MAu2mYFz4MgNrMMuhykAlTL4KCFUOiWMK3tLUyYEMTc: olm_decrypt: BAD_MESSAGE_MAC
[2018-08-29 19:01:23.331] [crypto] [info] failed to decrypt olm message (0, ttphBPXpykpTzidIxLPCI+jWz4FHtVH/IdChAw92QTY) with QRIpLLO+AtKPqyypXPacU9h0l66XDvOp0ePONXLUEkg: olm_decrypt: BAD_MESSAGE_MAC
[2018-08-29 19:01:23.332] [crypto] [info] failed to decrypt olm message (0, ttphBPXpykpTzidIxLPCI+jWz4FHtVH/IdChAw92QTY) with WlqKcNPrBDPfDsLkCygKiM9uk4i+nZEZM4IxiyuqM8U: olm_decrypt: BAD_MESSAGE_MAC
[2018-08-29 19:01:23.333] [crypto] [info] failed to decrypt olm message (0, ttphBPXpykpTzidIxLPCI+jWz4FHtVH/IdChAw92QTY) with cc35HRuzaeU3hbVYXS8kdyloOWS/oiSDelHG5yFyHgI: olm_decrypt: BAD_MESSAGE_MAC
[2018-08-29 19:01:23.334] [crypto] [info] failed to decrypt olm message (0, ttphBPXpykpTzidIxLPCI+jWz4FHtVH/IdChAw92QTY) with eti8/8djMz97c9U58Yaw7SpuR7jcS+d6m6BptqlpK4Y: olm_decrypt: BAD_MESSAGE_MAC
[2018-08-29 19:01:23.335] [crypto] [info] failed to decrypt olm message (0, ttphBPXpykpTzidIxLPCI+jWz4FHtVH/IdChAw92QTY) with ooabu92U2McST1+9G5eUTxOO4ezOojBAoJ9x3xmxuIs: olm_decrypt: BAD_MESSAGE_MAC
[2018-08-29 19:01:23.335] [crypto] [info] failed to decrypt olm message (0, ttphBPXpykpTzidIxLPCI+jWz4FHtVH/IdChAw92QTY) with pbJBJr7l4tabIC/KlvIr6DBTCWhPIMHnkSpwhNcdpA0: olm_decrypt: BAD_MESSAGE_MAC
[2018-08-29 19:01:23.336] [crypto] [info] failed to decrypt olm message (0, ttphBPXpykpTzidIxLPCI+jWz4FHtVH/IdChAw92QTY) with sefXc/8zXbRQ6BsBNDtqplikwUuO59foMlYjUzmtmwE: olm_decrypt: BAD_MESSAGE_MAC
[2018-08-29 19:01:23.336] [crypto] [info] opening olm session with @unclechu:matrix.org
[2018-08-29 19:01:23.336] [crypto] [critical] failed to create inbound session with @unclechu:matrix.org: create_inbound_session_from: BAD_MESSAGE_KEY_ID
[2018-08-29 19:01:23.671] [ui] [info] [ZoU9sqpKVAvCHfuVgiIXvz46rFd9MnLI] message was received by the server
[2018-08-29 19:01:23.995] [crypto] [info] Could not find inbound megolm session (!CfNzrVthKynLVbqEAY:matrix.org, j2Lti2lJhy6hYf0bXFO+mIl7YxXW6Yq3GshQPxtCS8M, @unclechu:matrix.org)
@unclechu Do you see any errors/warnings related to one-time keys in the logs? I suspect there might be some bad one time keys uploaded in the server.
@mujx I sent whole part of the log since I created new room. Do you mean if I see something above?
I just restart nheko and here what I see:
λ ./nheko-nightly-x86_64.AppImage
shutdown: uninitializedshutdown: uninitialized
FilteredTextEdit(0x309bab0) does not have a property named "borderColor"
FilteredTextEdit(0x309bab0) does not have a property named "borderColor"
[2018-08-29 19:16:15.490] [db] [info] restoring state from cache
[2018-08-29 19:16:15.503] [db] [info] sessions restored
[2018-08-29 19:16:15.504] [db] [info] loading 150 rooms
[2018-08-29 19:16:15.529] [ui] [info] starting nheko 0.5.4-183975b
[2018-08-29 19:16:15.978] [crypto] [info] ed25519 : SOME-HASH
[2018-08-29 19:16:15.978] [crypto] [info] curve25519: SOME-ANOTHER-HASH
[2018-08-29 19:16:16.112] [ui] [info] initialize room list
After I sent a message to E2EE room and tried to send another (without success):
[2018-08-29 19:18:34.154] [crypto] [info] Could not find inbound megolm session (!ROOM-ID:matrix.org, SOME-HASH, @unclechu:matrix.org)
I meant to search in the nheko.log file in ~/.cache/nheko for the following string
failed to upload one time keys
@mujx Nothing found by:
cat nheko*.log | grep -i 'failed to upload one time keys'
https://github.com/mujx/nheko/issues/422 is blocker to check if this bug disappears after login to new session.
@mujx After new sync everything is okay, I'm also able to see my own messages after restart. Maybe this issue supposed to be kept open until some mechanism will be implemented to solve this issue automatically?