Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Enhancement: Matrix commander is slow, it seems to temporarily hang due to syncing #91

Open
lefuturiste opened this issue Aug 22, 2022 · 22 comments

Comments

@lefuturiste
Copy link

Hi,

I'm testing this software and no matter what I try to do it always freeze for one minute after finally doing what I want.

I wanted to send a message to a specific room, I issued this command :

time matrix_commander/matrix-commander --debug --message "wtf is this taking too much time" --room "!REDACTED:matrix.org"
2022-08-22 08:13:59,747:    DEBUG: matrix-commander: Debug is turned on. debug count=1
2022-08-22 08:13:59,748:    DEBUG: matrix-commander: Separator is set to "    " of length 4. E.g. Col1    Col2.
2022-08-22 08:13:59,748:    DEBUG: matrix-commander: Encryption is always enabled. It cannot be turned off.
2022-08-22 08:13:59,748:    DEBUG: matrix-commander: All arguments are valid. All checks passed.
2022-08-22 08:13:59,748:    DEBUG: matrix-commander: Trying to create a PID file to store process id 111265.
2022-08-22 08:13:59,748:    DEBUG: matrix-commander: Successfully created PID file "/home/mbess/.run/matrix-commander.f8205c61-9a42-4277-af59-dd043998d100.pid" to store process id 111265.
2022-08-22 08:13:59,748:    DEBUG: matrix-commander: Stdin pipe is assigned to "none".
2022-08-22 08:13:59,748:    DEBUG: matrix-commander: SSL will be used. Default SSL certificate validation will be done for this connection.
2022-08-22 08:13:59,749:    DEBUG: matrix-commander: Credentials file existed. So this is the one we suggest to use. file: credentials.json
2022-08-22 08:13:59,749:    DEBUG: matrix-commander: Found an existing store in directory "store" (local or arguments). It will be used.
2022-08-22 08:14:01,209:    DEBUG: matrix-commander: Logged in using stored credentials from credentials file "credentials.json".
2022-08-22 08:14:01,492:    DEBUG: matrix-commander: restore_login successful. Successfully logged in as user @lefuturiste:matrix.org via restore_login. Response is: WhoamiResponse(uuid='', start_time=None, end_time=None, timeout=0, transport_response=<ClientResponse(https://matrix.org/_matrix/client/r0/account/whoami?access_token=XXX) [200 OK]>
<CIMultiDictProxy(REDACTED)>
, user_id='@lefuturiste:matrix.org')

2022-08-22 08:14:01,494:    DEBUG: matrix-commander: Room(s) from --room: ['!REDACTED:matrix.org']
2022-08-22 08:14:01,495:    DEBUG: matrix-commander: Room(s) from --user: [], no users were specified.
2022-08-22 08:14:01,495:    DEBUG: matrix-commander: Room(s) or user(s) were provided via command line. Overwriting room id from credentials file with rooms "['!REDACTED:matrix.org']" from command line.
2022-08-22 08:14:01,495:    DEBUG: matrix-commander: Rooms are: ['!REDACTED:matrix.org']
2022-08-22 08:15:37,089:    DEBUG: matrix-commander: stdin is not ready. A pipe could be used, but pipe could be empty, stdin could also be a keyboard.
2022-08-22 08:15:37,089:    DEBUG: matrix-commander: Don't read from keyboard because there are messages provided in arguments with -m.
2022-08-22 08:15:37,089:    DEBUG: matrix-commander: Messages from pipe:         []
2022-08-22 08:15:37,089:    DEBUG: matrix-commander: Messages from keyboard:     []
2022-08-22 08:15:37,089:    DEBUG: matrix-commander: Messages from command-line: ['wtf is this taking too much time']
2022-08-22 08:15:37,089:    DEBUG: matrix-commander: Sending message in format "text".
2022-08-22 08:15:39,474:     INFO: matrix-commander: This message was sent: "wtf is this taking too much time" to room "!REDACTED:matrix.org" as event "$DpMRKdtweZKUlplW4QuDz_ZHrTQSboL4320NsMCyQ4Q".
2022-08-22 08:15:39,474:    DEBUG: matrix-commander: This message was sent: "wtf is this taking too much time" to room "!REDACTED:matrix.org". Response: event_id=$DpMRKdtweZKUlplW4QuDz_ZHrTQSboL4XXXXXXXXXXX, room_id=!REDACTED:matrix.org, full response: RoomSendResponse(uuid='', start_time=None, end_time=None, timeout=0, transport_response=<ClientResponse(https://matrix.org/_matrix/client/r0/rooms/!REDACTED:matrix.org/send/m.room.encrypted/REDACTED?access_token=REDACTED) [200 OK]>
<CIMultiDictProxy(REDACTED)>
, event_id='$DpMRKdtweZKUlplW4QuDz_ZHrTQSboL4320XXXXXXXX', room_id='!REDACTED:matrix.org'). 
2022-08-22 08:15:39,474:    DEBUG: matrix-commander: Message send action finished.
2022-08-22 08:15:39,475:    DEBUG: matrix-commander: The program matrix-commander.py left the event loop.
2022-08-22 08:15:39,475:    DEBUG: matrix-commander: Cleanup: cleaning up.

________________________________________________________
Executed in  100.81 secs    fish           external
   usr time   67.04 secs    1.70 millis   67.04 secs
   sys time    1.05 secs    0.15 millis    1.05 secs

However this is taking 67 secs! for a single message? Where it did go all wrong?
It's seems to be waiting for some thing between
2022-08-22 08:14:01,495: DEBUG: matrix-commander: Rooms are: ['!REDACTED:matrix.org']
and
2022-08-22 08:15:37,089: DEBUG: matrix-commander: stdin is not ready. A pipe could be used, but pipe could be empty, stdin could also be a keyboard.

My environnement:

  • Matrix commander Git cloned 88cb0e4 (I also tried using the version on pypip.org but no success)
  • Python 3.10.5
  • Linux 5.15.60.1-lts x86_64

Anyway thanks for your work

@nukeador
Copy link

Getting similar issue, even 2 minutes wait sometimes. I was told it's maybe because I'm using matrix.org homeserver which is known to be slow, but I don't see that slowness when sending messages using element.

@lefuturiste
Copy link
Author

Getting similar issue, even 2 minutes wait sometimes. I was told it's maybe because I'm using matrix.org homeserver which is known to be slow, but I don't see that slowness when sending messages using element.

yes and this is in a matrix.org server

@lefuturiste
Copy link
Author

I tried to debug a little bit and dig deeper in the code but I didn't found any evident issue, I think I need to profile the python code

@nukeador
Copy link

Also might be worth bench-marking using other homeservers or even a local one.

@opk12
Copy link

opk12 commented Aug 30, 2022

@ users

See comments below line 5805. Syncing means updating the on-disk cache, by downloading all events from all rooms since the last app execution. This typical workflow of any Matrix client goes unnoticed in a graphical client, because of user interaction (browsing to the room, typing the message).

If you want encryption, syncing is necessary (encryption requires downloading state events, you need to know which devices are trusted or not, and matrix-nio is designed to require a sync if you want encryption).

@8go

  1. One can send non-encrypted in matrix-nio without syncing. What about a command-line flag to disable the sync explicitly, for a single execution?

  2. This is not only to send a message, but also any write-only operation (banning, ...) For example, OpenStreetMap Humanitarian wants to automate banning with matrix-commander across 20 rooms (like a home-made Mjölnir).

  3. When the sync is running, what about a descriptive message Syncing...

@ myself

There is an unsupported way in matrix-nio to send encrypted without syncing. On my test setup, I did the initial sync. For the following executions, instead of the sync, async_client.rooms[room_id] = nio.rooms.MatrixRoom(room_id=room_id, own_user_id=user_id, encrypted=True). I'm writing it for anyone who reads this and wants to try locally (or open a matrix-nio feature request).

@nukeador
Copy link

Note from my testings: Performing a bulk ban in different rooms is just taking a few seconds per room, nothing compared with sending a message.

lefuturiste added a commit to lefuturiste/matrix-commander that referenced this issue Sep 13, 2022
@8go 8go changed the title Matrix commander seems to hangs Enhancement: Matrix commander is slow, it seems to temporarily hang Oct 2, 2022
@8go 8go changed the title Enhancement: Matrix commander is slow, it seems to temporarily hang Enhancement: Matrix commander is slow, it seems to temporarily hang due to syncing Oct 2, 2022
@8go
Copy link
Owner

8go commented Oct 2, 2022

@opk12 @nukeador @lefuturiste

3 When the sync is running, what about a descriptive message Syncing...

OK, that can be done.

1 What about a command-line flag to disable the sync explicitly, for a single execution?

Doable. Yes. But this allows the user to shoot oneself into the foot.
I am not sure what can go wrong if used incorrectly. Let's discuss option (1) a bit more.
I really do not know what the worst case scenario is. Can the event database be somehow corrupted? Can one lose messages or other events? Will events just be out-of-order? First matrix-nio, then matrix, synapse, then the DB. Many dependencies/layers and I am not sure of the outcome.

What is your opinion? Please share!

@opk12
Copy link

opk12 commented Oct 2, 2022

matrix-nio

I search for sync in the documentation's page Examples. The examples send room events before syncing:

The only case where the examples sync before sending a room event is when encryption is needed, in Manual encryption key verification.

Protocol

The specification to send an event is 7.8 Sending events to a room. I successfully call it with curl as in:

#! /bin/bash
curl \
        -X PUT "https://$HOMESERVER/_matrix/client/v3/rooms/$ROOM_ID/send/m.room.message/$(date +%s%N)" \
        -H "Authorization: Bearer $ACCESS_TOKEN" \
        -d '{"body": "'"$BODY"'", "msgtype": "m.text"}'

The parameters are: homeserver, room id, transaction id, access token, message body.
No parameter requires updating the local state and this curl is an example of a client that does send without syncing.

Uploading a file does not touch a room (you upload to a server, not a room) and is at 1.1.9.2 under 1.1.9 Content repository and does not require storing local state.

Server and database

A client's ability to make the server (Synapse, DB, ...) not follow the protocol (corrupt, alter the room's past, alter future behavior, ...) is a security issue on the server and not a fault of the client.

@opk12
Copy link

opk12 commented Oct 2, 2022

That the documentation sends before syncing also implies that you can send without syncing at all, because a network error during the later syncing would otherwise break / corrupt matrix-nio.

@8go
Copy link
Owner

8go commented Oct 2, 2022

Thank you @opk12 for your research and your summary.

The matrix-nio examples do not convince me (as I wrote some of these examples myself) and they were written to keep things extremely simple, not to be best-practice code.

The Protocol example convinces me a lot more.

I take it, you @opk12 are voting in favor of a --skip-sync option.

Should there be a --skip-sync option and therefore the user decides if to use it or not by setting the option (default is sync==on)?

Or should there be no user option, no command-line option, but matrix-commander decides when to sync and when not to sync?
Should it automatically skip syncing if there is only (a) sending, (b) xxx, ... ?

Please share your Thoughts? Input? Opinions?

@opk12
Copy link

opk12 commented Oct 2, 2022

The matrix-nio examples do not convince me (as I wrote some of these examples myself) and they were written to keep things extremely simple, not to be best-practice code.

If that's the case, this should be written next to each example, because people are jumping to the examples through links (not read the whole page) and use them as reference (copy-paste).

But then, is it possible that matrix-nio needs syncing to send? For example, in theory it could

  • add the sent event to the local cache (rather than downloading it in the next sync), thus expect some event ordering from the next sync
  • save the transaction ID and increment on each send
  • do these in future versions

@8go
Copy link
Owner

8go commented Oct 2, 2022

Since I do not dare to give a definite answer, in short I am not sure, the best way forward might be to raise the question as an issue on matrix-nio, as an open-ended questions:

  • which operations, API calls require a sync?

plus additional narrow questions:

  • is sync required to send an encrypted message?
  • is sync required to send an unencrypted message?

@opk12
Copy link

opk12 commented Oct 2, 2022

1

Other possible questions that come to mind:

  • Why would one want to sync before sending
  • What does one lose by sending without sync

Because it might be possible, but with various levels of degraded functionality or security (which may be relevant or not, depending on the use case).

I don't know who maintains matrix-nio, but pointing out that it was you who wrote some of those examples might help if anyone who answers got a misconception based on reading the documentation. However, I hope that the fact that the examples were kept in the docs until today implies a partial acknowledgement.

2

I did not test encryption with matrix-commander, but do I understand it correctly that this message should be sent encrypted?

  1. I join room
  2. Someone else enables encryption
  3. I send with matrix-commander

If yes, then sending cannot default to auto-detect, and requiring an option for all operations would be consistent and more readable (when reading a command, I do not need GitHub just to remember whether it auto-skips) and would give the feeling that the program defaults to safety. What about --sync on|off to leave our future selves the choice of a future auto option or multiple safety levels.

@8go
Copy link
Owner

8go commented Oct 2, 2022

I just looked at my own source code, and back in the day I put in some comments as I wrote the code for send.

Around line 5881 you will find comments like:

        # Sync encryption keys with the server
        # Required for participating in encrypted rooms
       ...
        # must sync first to get room ids for encrypted rooms
       ...

There are 2 API calls: keys_upload() and sync(). Not sure how slow keys_upload() is in comparison to sync().

So, just blindly sending without a sync will not work in all cases. Things that could go wrong when doing a send without a sync:

  • room id not known, send fails

This is not a complete list of what can go wrong.
From this, I deduce that sync cannot just always be removed for send. By default we must keys_upload() and sync.

But send might work in (some) cases, when there is no new state, so nothing needs to be sync-ed.

At the same time, the code is written such that even if the sync fails, the send will take place. Meaning, right now there is no 100% guarantee the sync will be successful. What I am implying is what @opk12 said before: sending without syncing might lead to some error (room id not found, key not found) but it will not lead to corruption on the server. This is another way of saying: it might not be so dangerous to skip the sync, especially in cases where no new rooms where created, no new keys were created, etc.

--sync on|off might be the way to go. A value of off would skip for sending (just sending, not receiving). Should we name is --send-sync on|off to be more clear?

What is your preferred option name? --sync ? --send-sync ? --sync-send ? Opinions?

Then to make it even more complicated: the sync() API call has a boolean parameter full_state, so one could even envision: --sync none|partial|full. none meaning sync() will not be called. partial meaning sync(full_state=false). full meaning sync(full_state=true). But the documentation does not explain well what the difference between full_state true or false is. The docu just says:

full_state (bool, optional) – Controls whether to include the full state for all rooms the user is a member of. If this is set to true, then all state events will be returned.

@8go
Copy link
Owner

8go commented Oct 2, 2022

As you can see I have opened this issue on nio:
matrix-nio/matrix-nio#356

@opk12
Copy link

opk12 commented Oct 3, 2022

        # Sync encryption keys with the server
        # Required for participating in encrypted rooms
       ...
        # must sync first to get room ids for encrypted rooms
       ...
  • room id not known, send fails

This is not a complete list of what can go wrong. From this, I deduce that sync cannot just always be removed for send. By default we must keys_upload() and sync.

But note that all this is still about encryption. (And I wonder whether "get room ids" was related to some error message arising from async_client.rooms[room_id] not being populated automatically without a sync, as described above.)

--sync on|off might be the way to go. A value of off would skip for sending (just sending, not receiving). Should we name is --send-sync on|off to be more clear?

Once the local cache is updated, all operations will be affected. If "sync after X but before Y" is wanted, then it's clearer to call m-c once for X and once for Y.

Then to make it even more complicated: the sync() API call has a boolean parameter full_state

I think it mirrors the /sync endpoint's full_state parameter from the C-S API. It helps think about an extensible CLI, but I'd focus on getting the sync vs no sync thing, to avoid feature creep.

@8go
Copy link
Owner

8go commented Oct 3, 2022

I did some testing of my own today.

The setup matters a lot, so your mileage may vary drastically.

I tested only short send actions, like matrix-commander -m test or similar. Sending a small image, sending to 2 rooms, etc. I only tested encrypted messages/rooms.

What I found is:

  • connection took about 1/3 of the time
  • sync() varied strongly, but on the slower side it would take 1/3 of the time
  • the actual sending took 1/3 of the time

--sync off|full has been implemented. See commit 6a752f2

So, even turning sync off, for sending single messages, this only reduces the total time by at best 33%. Again, mileage may vary drastically. But it is not a magic bullet and no, now it does not go in the blink-of-an-eye.

For the time being the default is --sync full. If many people use --sync off without problems we might switch default to off in the future.

@8go
Copy link
Owner

8go commented Oct 11, 2022

See https://github.com/8go/matrix-commander-rs

An idea to improve performance 😄

Talk about it to your friends, post about it, spread the word and provide PRs. 🙏

And give it a ⭐ if you like the idea.

@opk12
Copy link

opk12 commented Oct 11, 2022

Eh but I fear that the network is the problem. The language impacts CPU usage, but m-c is spending a negligible time on the CPU; the usual symptoms of being CPU-bound are heating the computer, slowing down the system, or that the stack trace that appears at Ctrl + C contains some function that does a very long and tight loop (but that's not the case for m-c or for matrix-nio).

That said, it's not impossible that matrix-nio (as opposed to matrix-commander) does additional (necessary, or unnecessary) HTTP calls, so while I would not bet that switching the library could improve performance, I'd be happy to be proven wrong.

@opk12
Copy link

opk12 commented Oct 11, 2022

--sync off|full has been implemented. See commit 6a752f2

Thank you! I updated my script to use it.

@8go
Copy link
Owner

8go commented Oct 15, 2022

Another tip to avoid performance penalty: do NOT use room aliases, but use room ids instead. Room aliases need to be looked up, adding another REST call to the server.

@8go
Copy link
Owner

8go commented Oct 25, 2022

If you just want to login, verify and send a text or a file, you can now use the Rust version. Rust version cannot listen (hoping for PRs). Rust version is also not optimized (--sync off does not yet exist), but still you can try and see if it makes any difference at all in performance.

Feedback is welcome.

Check out:

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants