Local xpra is *very* laggy. The most prominent issue is that keyboard input is delayed by about a second, but also scrolling in GTK apps is laggy (might be caused by input lag, though).
As per IRC, I already tried debugging both client and server with -d keyboard,pointer and it does show that the server receives events delayed.
I also ran the server under strace, as I thought it might be blocked in some poll() loop, but that looked fine (all poll() calls return almost immediately.
info by bug report tool
Since it isn't laggy for anyone else (that I know of), please add more details as per wiki/ReportingBugs so we can identify the difference with your setup.
I attached the zip that's created by the built-in bug report took. What else do you need?
What else do you need?
There are many questions on the wiki/ReportingBugs page, it is impossible for us to know which ones will be relevant. They key point is what something is different on your setup.
So I made a completely fresh Kubuntu 18.04.1 install and the behavior is pretty much the same. But as part of answering the question I found that disabling AV sync makes a huge difference, basically I cannot say it's laggy anymore.
what operating system is used on both the client and server, including the full version details
$ uname -a Linux tmartitz-pc 4.15.0-30-generic #32-Ubuntu SMP Thu Jul 26 17:42:43 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
$ glxinfo | grep GL\ renderer OpenGL renderer string: Mesa DRI Intel(R) HD Graphics 530 (Skylake GT2)
Kubuntu 18.04.1 comes with KDE Frameworks 5.44, Plasma 5.12 LTS and KDE Applications 17.12.3
$ dpkg -s xpra Package: xpra Status: install ok installed Priority: optional Section: x11 Installed-Size: 15697 Maintainer: Antoine Martin <antoine@devloop.org.uk> Architecture: amd64 Version: 2.3.2-r19729-1 Replaces: ffmpeg-xpra Depends: python (<< 2.8), python (>= 2.7~), python:any (<< 2.8), python:any (>= 2.7.5-5~), libavcodec57 (>= 7:3.4.2) | libavcodec-extra57 (>= 7:3.4.2), libavformat57 (>= 7:3.4.2), libavutil55 (>= 7:3.4.2), libc6 (>= 2.14), libglib2.0-0 (>= 2.12.0), libgtk2.0-0 (>= 2.24.0), libpam0g (>= 0.99.7.1), libswscale4 (>= 7:3.4.2), libsystemd0, libturbojpeg, libvpx5 (>= 1.6.0), libwebp6 (>= 0.5.1), libx11-6 (>= 2:1.2.99.901), libx264-152, libxcomposite1 (>= 1:0.3-1), libxdamage1 (>= 1:1.1), libxext6, libxfixes3, libxi6 (>= 2:1.2.99.4), libxkbfile1, libxrandr2 (>= 2:1.2.99.2), libxtst6, python-gtk2, x11-xserver-utils, xserver-xorg-video-dummy, python-gtkglext1, python-opengl, python-numpy, python-pil, python-rencode, python-lz4 Recommends: libavcodec57, libx264-148, dbus-x11, python-dbus, python-setproctitle, python-cryptography, python-kerberos, python-gssapi, gstreamer1.0-pulseaudio, gstreamer1.0-alsa, gstreamer1.0-plugins-base, gstreamer1.0-plugins-good, gstreamer1.0-plugins-ugly, python-gst-1.0, cups-filters, cups-common, cups-pdf, python-cups, python-pyinotify, python-opencv, v4l2loopback-dkms, openssh-client, ssh-askpass, websockify, libjs-jquery, keyboard-configuration, sshpass Suggests: openssh-server, gnome-shell-extension-top-icons-plus, pulseaudio, pulseaudio-utils, python-avahi, python-netifaces, python-yaml, python-pycuda, libnvidia-encode1, python-lzo, libxvidcore4 Conflicts: ffmpeg-xpra Conffiles: /etc/dbus-1/system.d/xpra.conf d58c2d718e3eaa799ed0223ab21dd2a5 /etc/default/xpra 691afa8edec7c167de80fcfd407b0b37 /etc/pam.d/xpra eaf372a294b1e2e1a1c9123cdeb03a41 /etc/xpra/conf.d/05_features.conf f8bbd7527e86e50d2fe542470a14243e /etc/xpra/conf.d/10_network.conf 9549d386ce697a16e6e4edbc425466e3 /etc/xpra/conf.d/12_ssl.conf 916ae779caa1a9e4ff3eb00cf9881ccc /etc/xpra/conf.d/15_file_transfers.conf 3d8e892d0b1b8ced4da21feac3a87e0f /etc/xpra/conf.d/16_printing.conf 55ded8177f08ff99629c34ef059ca163 /etc/xpra/conf.d/20_sound.conf e805d4bd159a849529e3bc199e8958ea /etc/xpra/conf.d/30_picture.conf 2568844319ae92e81e3f3d14feb7c16a /etc/xpra/conf.d/35_webcam.conf 9f8857105624a48948078906acebf4ee /etc/xpra/conf.d/40_client.conf 2756819619b5c97839e680b3d19aaab0 /etc/xpra/conf.d/42_client_keyboard.conf f1be5c9d8ef62d2677f1351ee4709ac8 /etc/xpra/conf.d/50_server_network.conf 396e24f643bf3279360e74afa367fe84 /etc/xpra/conf.d/55_server_x11.conf 82a4f3a74d998512955f2ca749172a76 /etc/xpra/conf.d/60_server.conf 09fe862cd1ea649ddcbfcc7e04cde92e /etc/xpra/conf.d/65_proxy.conf a8d85747e0a2886341493a07977c390b /etc/xpra/cuda.conf 903827a1fd15d11fb4460ce2fc15c653 /etc/xpra/xorg-uinput.conf 2913f509d04b5cf4432d356716874b95 /etc/xpra/xorg.conf 4b6c318aef446f6585c83caee678880a Description: tool to detach/reattach running X programs Xpra gives you the functionality of GNU Screen for X applications. . It allows the user to view remote X applications on their local machine, and disconnect and reconnect from the remote machine without losing the state of the running applications. . Unlike VNC, these applications are "rootless". They appear as individual windows inside your window manager rather than being contained within a single window. Homepage: http://xpra.org/
changes made to the default configuration, if any. This can be shown with the command: "xpra showconfig"
I have cleared all custom config. xpra showconfig is attached.
the desktop environment, window manager used - if applicable
KDE with kwin (see above)
anything that would make the setup unusual: number of screens, resolution, virtualization software, access via another remote desktop tool (VNC, RDP, ..), etc
I normally use 3 screens, one of them rotated, but the behavior is the same with only one output. No other remote desktop involved.
the network setup, bandwidth constraints (ie: LAN or DSL)
local
the full command lines used both on the server and client
$ ps aux | grep xpra tmartitz 3075 5.4 1.5 1338604 369492 ? Sl 10:44 4:19 /usr/bin/python2 /usr/bin/xpra start :10 --start-via-proxy=no tmartitz 3076 0.0 0.8 880552 205320 ? Ssl 10:44 0:04 /usr/lib/xorg/Xorg-for-Xpra-:10 -noreset -novtswitch -nolisten tcp +extension GLX +extension RANDR +extension RENDER -auth /home/tmartitz/.Xauthority -logfile /run/user/1000/xpra/Xorg.:10.log -configdir /run/user/1000/xpra/xorg.conf.d/3075 -config /etc/xpra/xorg.conf -depth 24 :10 tmartitz 3122 2.3 0.0 326532 8404 ? S<l 10:44 1:52 pulseaudio --start -n --daemonize=false --system=false --exit-idle-time=-1 --load=module-suspend-on-idle --load=module-null-sink sink_name="Xpra-Speaker" sink_properties=device.description="Xpra\ Speaker" --load=module-null-sink sink_name="Xpra-Microphone" sink_properties=device.description="Xpra\ Microphone" --load=module-native-protocol-unix socket=/run/user/1000/xpra/pulse-:10/pulse/native --load=module-dbus-protocol --load=module-x11-publish --log-level=2 --log-target=stderr --enable-memfd=no tmartitz 3604 5.3 1.7 2121604 438064 pts/1 Sl+ 10:44 4:10 /usr/bin/python2 /usr/bin/xpra attach :10 tmartitz 3683 6.4 0.1 1215724 40680 pts/1 Sl+ 10:45 5:03 /usr/bin/python2 /usr/bin/xpra _sound_play - - opus 1.0 tmartitz 3722 12.4 0.1 1009540 40980 ? Sl 10:45 9:44 /usr/bin/python2 /usr/bin/xpra _sound_record - - pulsesrc device=Xpra-Speaker.monitor opus 1.0 tmartitz 3756 0.0 0.0 25840 6768 ? Ss 10:45 0:00 /usr/bin/python2 /usr/bin/xpra_signal_listener tmartitz 5512 0.0 0.0 14780 1048 pts/3 S+ 12:03 0:00 grep xpra
the server log file (or output if no log file is used)
:10.log is attached
the environment (ie: %PATH% on MS Windows, $PATH and $LD_LIBRARY_PATH on Linux, etc)
env.txt is attached
"xpra info" for the session
xpra-info.txt is attached
how the software was installed and what version (in full)
I installed it through package managers using the repositories on winswitch.org, version see above (latest stable)
is this a new problem or a regression? (if a regression, when did it start?)
I think it wasn't that bad a couple of years ago, but it's like this since a long time by now (I was too lazy to report early and hoped it would be fixed by the new graphics stack in 18.04)
are there other bugs that are similar? are there other unusual issues / behaviour apart from this particular bug?
Not that I can tell for both questions
is it reproducible reliably? and if so, how?
Always
does this happen with all picture encodings?
Can't change with local xpra
does switching off certain features make a difference (ie: sound, opengl, clipboard)
Actually, this question gave a key hint. I did play with some settings, and disabling audio-video sync makes a huge difference. I would say the laggy behavior does not occur with AV sync disabled!
include relevant parts of the log files - including enough context to investigate (not just the last line showing the error message, but not necessarily the whole log file either)
What log files would be relevant?
does re-connecting help?
No
does it happen with other type of clients (different OS, etc)
I have only Linux clients. I have one at home (for home office) and it's laggy as well but I can't say for sure it's not the slow internet connection.
try to include the output of some of the diagnosis tools we bundle (ie: Network_Info.exe and Encoding_Info.exe on MS Windows, net_util.py and loader.py everywhere else)
Please say if this is still relevant after my AV sync finding.
Sorry, I have to take the av-sync finding back. I made an error on my side. Disabling av-sync *does not* do anything.
But perhaps you can tell if it's truly disabled because to me it looks still like being enabled?
$ xpra info | grep av-sync client.argv=('/usr/bin/xpra', 'attach', '--av-sync=no', ':10') client.av-sync=True client.av-sync.client=0 client.av-sync.delta=0 client.av-sync.enabled=False client.av-sync.total=75 features.av-sync=True window.1.av-sync.current=75 window.1.av-sync.enabled=True window.1.av-sync.target=75 window.9.av-sync.current=75 window.9.av-sync.enabled=True window.9.av-sync.target=75 window.10.av-sync.current=0 window.10.av-sync.enabled=True window.10.av-sync.target=0
KDE with kwin (see above)
I doubt that's the source of the problem, but if nothing else helps then it would be worth trying a different WM as I very rarely test the client under KDE.
Actually, this question gave a key hint. I did play with some settings, and disabling audio-video sync makes a huge difference. I would say the laggy behavior does not occur with AV sync disabled!
Then that's the problem. What I don't understand is why you would have AV sync with local connections. Those are meant to use mmap, and mmap is not affected by av-sync. The only encodings that use av-sync are the video encodings (vp8, vp9, h264 and hevc), and those don't usually trigger unless the application you run is refreshing at a high framerate. What is the application you are forwarding? Does the problem manifest itself with a simple xterm?
Can you try to turn off audio completely? Start with --speaker=no --microphone=no
Please say if this is still relevant after my AV sync finding.
I think there's enough data in this ticket, thanks!
Actually, this question gave a key hint. I did play with some settings, and disabling audio-video sync makes a huge difference. I would say the laggy behavior does not occur with AV sync disabled!
Then that's the problem.
av-sync is *not* the problem, the previous post was based on an error on my side (the window I tested wasn't running under xpra).
Unless you can give me steps to reproduce the laggyness, I will have to close this ticket as "needinfo".
My prime suspect would be the clipboard.
FWIW, I'm slowly working my way back to looking at this, I need xpra working for the next stage of one or two projects, but "real world" stuff has intervened recently :(
Alright, so I went into a Kubuntu live install in order to repro this on a truly clean system.
I only changed language and input to German, and then installed xpra and did some test.
I tested with kate first and thought it's snappy as expected. Then I checked debug / support files and found no real difference to my system. Only "input-ethod" seems to be at keep for my problematic although I never explicitly changed this back from the default of none (the live system has input-method = none).
But then I thought I should try the apps I use, that's mainly Geany and some gtk based terminals. And here I found the culprit: Geany was laggy. Much more so than kate.
So I think the root issue seems to be on GTK apps, mayble only if running on a KDE platform.
Do you have an idea?
Oh and changing input-method from keep to none or vice versa doesn't make a difference to the GTK apps.
So I think the root issue seems to be on GTK apps, mayble only if running on a KDE platform. Do you have an idea?
You can enable paint debugging to see if the app is repainting too much:
XPRA_OPENGL_PAINT_BOX=1 xpra attach ...
(assuming that you have opengl enabled on the client)
Seems rather calm. In a terminal application only the edited line flashes according to the cursor and if I hit enter (to add a new line) the full widget flashes only very briefly. So far as expected.
Also, I found previously, that the input events reach the server delayed, see description:
As per IRC, I already tried debugging both client and server with -d keyboard,pointer and it does show that the server receives events delayed.
As per IRC, I already tried debugging both client and server with -d keyboard,pointer and it does show that the server receives events delayed.
Then I can only recommend that you try to run a packet sniffer between the server and client, enable network logging with "-d network" and see if the delay comes from the network or from xpra processing those packets too slowly.
(running with XPRA_USE_ALIASES=0 xpra -z 0 ...
makes the packets more human-readable)
If somehow xpra is abnormally slow, then it's usually something messing up with X11 or xpra's main loop (ie: clipboard sync, which you can try to disable).
Uhm, this is local xpra (mmap'd), what kind of traffic should I expect? On which interface (lo?)
Uhm, this is local xpra (mmap'd), what kind of traffic should I expect? On which interface (lo?)
Yes, you can connect to tcp://127.0.0.1:10000
for example after using --bind-tcp=0.0.0.0:10000
on the server.
I will have to close this ticket as NEEDINFO unless I can reproduce it.
I provided steps to reproduce. Is that not sufficient?
Just had a quick look at this .. using latest Kubuntu daily-live (2018-10-14 00:06, MD5: 020460f18bd227886c2fb1a2a21990cf) and latest Xpra beta (presumably 20683, but forgot to actually check, sorry), I can't reproduce any lag with Geany - was lovely and smooth even on my low power box, apart from a brief delay to cache the drop down menus. No problem with keyboard input.
I tried to experiment with input method but I kept getting messages about not being able to connect to fcitx, which I decided I wasn't up for investigating!
You used different versions of kubuntu and xpra (I used stable), so its not really comparable. Now I don't know if it's your system (maybe sound or graphics driver make a difference?) or the SW versions.
Can you post some system details?
Ah, OK, didn't know what versions you'd used for the live test. You did say you used 18.10 in comment 20 though?
Anyway, it's an Apollo Lake Intel SoC box..
CPU: Quad core Intel Celeron N3450 (-MCP-) speed/max: 922/2200 MHz Graphics: Card: Intel Device 5a85
00:02.0 VGA compatible controller: Intel Corporation Device 5a85 (rev 0b) 00:0e.0 Audio device: Intel Corporation Celeron N3350/Pentium N4200/Atom E3900 Series Audio Cluster (rev 0b)
Can't check what drivers the Live image used just now but I'd imagine it was i915 kernel-side and modeset for X.
For some reason I'd dropped off IRC but joined again now - tc424 there as well. Shout if you want more details..
and latest Xpra beta (presumably 20683, but forgot to actually check, sorry)
You used different versions of kubuntu and xpra (I used stable)
r20683 is 2.4 stable.
Today I made an interesting observation:
I upgraded my system, so that xpra 2.4 stable was installed. After a reboot, I thought the problem disappeared, and I imagined that a important change was made to 2.4.
However, after about 20min of using the system onwards, the problem started to reappear. Then I closed two affected apps and restarted them, and I see that the input delay is close to zero again (I wouldn't say it's indistinguishable from KDE apps like kate under xpra, but it's almost acceptable).
After about 20 minutes the problem appears again.
So the conclusion is that the problem doesn't immediately appear after starting the affected programs, but only after some time (I wouldn't say the apps need to be actively used from my observations).
Please capture xpra info
both before and after the problem appears so we can see what is different.
Then I closed two affected apps and restarted them, and I see that the input delay is close to zero again (I wouldn't say it's indistinguishable from KDE apps like kate under xpra, but it's almost acceptable).
Be aware that some KDE applications are known to have had pathological paint behaviour in the past, this can contribute to make things slower. That said, on a local connection with mmap enabled this should be a non-issue, just a small waste of CPU cycles.
Next time, try the "re-initialize windows" action from the system tray menu. You will probably get the same effect. (or toggle opengl on and off from the same menu)
The only noticeable difference between the good and bad log you provided is the batch delay in the bad one: it's high enough that one would notice (around >100ms).
I already tried debugging both client and server with -d keyboard,pointer and it does show that the server receives events delayed.
Are you certain this is the case?
Can you post a sample server log? If you also run both the client and server with -d keyboard,pointer
and remote logging enabled (it is enabled by default) then the server log will have both client and server events, including the original timecodes from the client end.
The batch delay would not affect input events being received and processed by the server, but it would cause the screen updates to be delayed before being sent to the client.
Assuming that the problem does come from the batch delay rather than an "input lag" then we need to figure out why it reaches >100ms - which should never happen on a local connection.
For that please provide the -d stats
server log output around the time when the problem occurs.
You may also want to try --bandwidth-detection=no
on the client. (there are recent reports that it does cause problems)
I'll collect the requested logs later on. Meanwhile I tried your suggestion to 1) re-initialize the windows and 2) toggle opengl.
1) The former did not make a difference, the delay remained the same. 2) Toggling OpenGL off an on again did make a difference. The delay reduced significantly.
I attached xpra info output after each (so xpra-info-gl-offon.txt is after 1) and 2))
Some of the slowness could be explained / fixed by #2037
Here is the log of a single key press.
It seems that I have misinterpreted the logs earlier. According to the timestamps there seems to be a delay of 100ms? But the actual delay is a lot higher.
I pressed arrow-down in a affected GTK-based terminal and watched the output of "journalctl -f" in another KDE-based terminal (which runs on the original DISPLAY not inside xpra).
What's interesting is that the entire bulk of the log lines that relate to the key press appears at once only after the affected application updates according to the keypress, so after the delay.
Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,661 client @55.787 parse_key_event(<gtk.gdk.Event at 0x7ff7c4d3f7d8: GDK_KEY_PRESS keyval=Down>, True)=<GTKKeyEvent object, contents: {'modifiers': ['mod2'], 'group': 0, 'string': '', 'keyname': 'Down', 'pressed': True, 'keyval': 65364, 'keycode': 116}> Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,663 client @55.787 handle_key_action(GLClientWindow(1 : gtk2.GLWindowBacking(1, (1920, 932), None)), <GTKKeyEvent object, contents: {'modifiers': ['mod2'], 'group': 0, 'string': '', 'keyname': 'Down', 'pressed': True, 'keyval': 65364, 'keycode': 116}>) wid=1 Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,663 client @55.789 key_handled_as_shortcut: shortcut(Down)=None Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,664 client @55.789 send_key_action(1, <GTKKeyEvent object, contents: {'modifiers': ['mod2'], 'group': 0, 'string': '', 'keyname': 'Down', 'pressed': True, 'keyval': 65364, 'keycode': 116}>) Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,665 set_keyboard_layout_group(0) config=KeyboardConfig(de / / None), current keyboard group=0 Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,665 get_keycode(116, Down, ('mod2',))=116 (native keymap) Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,665 process_key_action(['key-action', 1, 'Down', True, ('mod2',), 65364, '', 116, 0]) server keycode=116 Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,666 filtered_modifiers_set(['mod2'])=set(['mod2']) Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,666 filtered_modifiers_set(('mod2',))=set(['mod2']) Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,666 handle_key(1,True,Down,65364,116,('mod2',)) keyboard_sync=True Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,666 is_modifier(116) not found Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,667 handle keycode pressing 116: key 'Down' Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,667 fake_key(116, True) Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,668 scheduling key repeat timer with delay 600 for Down / 116 Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,668 key repeat timeout for Down / '116' - clearing it, now=38615.7958299, scheduled at 38615.795702 with delay=600 Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,668 handle_key(1,False,Down,65364,116,('mod2',)) keyboard_sync=True Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,669 is_modifier(116) not found Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,669 handle keycode unpressing 116: key 'Down' Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,669 fake_key(116, False) Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,765 client @55.890 parse_key_event(<gtk.gdk.Event at 0x7ff7c4d3f7d8: GDK_KEY_RELEASE keyval=Down>, False)=<GTKKeyEvent object, contents: {'modifiers': ['mod2'], 'group': 0, 'string': '', 'keyname': 'Down', 'pressed': False, 'keyval': 65364, 'keycode': 116}> Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,766 client @55.891 handle_key_action(GLClientWindow(1 : gtk2.GLWindowBacking(1, (1920, 932), None)), <GTKKeyEvent object, contents: {'modifiers': ['mod2'], 'group': 0, 'string': '', 'keyname': 'Down', 'pressed': False, 'keyval': 65364, 'keycode': 116}>) wid=1 Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,767 client @55.891 key_handled_as_shortcut: shortcut(Down)=None Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,767 client @55.892 send_key_action(1, <GTKKeyEvent object, contents: {'modifiers': ['mod2'], 'group': 0, 'string': '', 'keyname': 'Down', 'pressed': False, 'keyval': 65364, 'keycode': 116}>) Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,768 set_keyboard_layout_group(0) config=KeyboardConfig(de / / None), current keyboard group=0 Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,768 process_key_action(['key-action', 1, 'Down', False, ('mod2',), 65364, '', 116, 0]) server keycode=116 Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,768 filtered_modifiers_set(['mod2'])=set(['mod2']) Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,769 filtered_modifiers_set(('mod2',))=set(['mod2']) Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,769 handle_key(1,False,Down,65364,116,('mod2',)) keyboard_sync=True Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,769 is_modifier(116) not found Nov 15 12:57:57 tmartitz-pc xpra[1842]: 2018-11-15 12:57:57,769 handle keycode 116: key Down was already unpressed, ignoring
--bandwidth-detection=no on the client makes no difference.
Based on the log above, there does not seem to be any input lag.
There are two key events in that log: one GDK_KEY_PRESS
and one GDK_KEY_RELEASE
100 ms later.
From the moment the client parses the key event (parse_key_event
) until the server simulates pressing the corresponding key (fake_key
), only 6ms have passed. (4ms for the release)
So I think the whole premise of this ticket led us on a wild goose chase, there is no input lag and the problem is elsewhere.
My guess is that somehow the batch delay goes way up for the affected windows.
Please attach the -d stats
server debug output of a session that goes wrong.
I attached the requested logs. As you can see, only after a few minutes the batch delay ramps up to 260+ ms. I have seen values above 400ms too in previous sessions.
I guess you can interpret the logs better. I only see that starting with the high batch delay the following lines appear start to appear in the log:
Nov 27 09:43:41 tmartitz-pc xpra[1807]: 2018-11-27 09:43:41,703 calculate_batch_delay for wid=1 current batch delay=74, last update 60 seconds ago Nov 27 09:43:41 tmartitz-pc xpra[1807]: 2018-11-27 09:43:41,703 update_batch_delay: damage-network-delay : 0.99,0.51 {u'avg': 40, u'recent': 40} Nov 27 09:43:41 tmartitz-pc xpra[1807]: 2018-11-27 09:43:41,703 update_batch_delay: client-decode-speed : 0.88,0.04 {u'avg': 90, u'recent': 76} Nov 27 09:43:41 tmartitz-pc xpra[1807]: 2018-11-27 09:43:41,703 update_batch_delay: damage-rate : 1.00,0.00 {'max_latency': 100, 'elapsed': 172} Nov 27 09:43:41 tmartitz-pc xpra[1807]: 2018-11-27 09:43:41,704 update_batch_delay: client-latency : 0.49,0.25 {u'target': 5, u'weight_multiplier': 355, u'smoothing': u'sqrt', u'aim': 800, u'aimed_avg': 238, u'div': 1000, u'avg': 2, u'recent': 1} Nov 27 09:43:41 tmartitz-pc xpra[1807]: 2018-11-27 09:43:41,704 update_batch_delay: client-ping-latency : 0.48,0.12 {u'target': 5, u'weight_multiplier': 161, u'smoothing': u'sqrt', u'aim': 949, u'aimed_avg': 233, u'div': 1000, u'avg': 1, u'recent': 1} Nov 27 09:43:41 tmartitz-pc xpra[1807]: 2018-11-27 09:43:41,704 update_batch_delay: server-ping-latency : 0.62,0.10 {u'target': 6, u'weight_multiplier': 163, u'smoothing': u'sqrt', u'aim': 949, u'aimed_avg': 380, u'div': 1000, u'avg': 2, u'recent': 2} Nov 27 09:43:41 tmartitz-pc xpra[1807]: 2018-11-27 09:43:41,704 update_batch_delay: packet-queue-size : 0.00,0.05 {u'target': 1000, u'weight_multiplier': 48, u'smoothing': u'sqrt', u'aim': 250, u'aimed_avg': 0, u'div': 1000, u'avg': 2, u'recent': 0} Nov 27 09:43:41 tmartitz-pc xpra[1807]: 2018-11-27 09:43:41,704 update_batch_delay: packet-queue-pixels : 0.00,0.00 {u'target': 1000, u'weight_multiplier': 0, u'smoothing': u'sqrt', u'aim': 250, u'aimed_avg': 0, u'div': 962684000, u'avg': 0, u'recent': 0} Nov 27 09:43:41 tmartitz-pc xpra[1807]: 2018-11-27 09:43:41,704 update_batch_delay: compression-work-queue : 0.00,0.04 {u'target': 1000, u'weight_multiplier': 41, u'smoothing': u'logp', u'aim': 250, u'aimed_avg': 0, u'div': 1000, u'avg': 1, u'recent': 0} Nov 27 09:43:41 tmartitz-pc xpra[1807]: 2018-11-27 09:43:41,704 update_batch_delay: damage-packet-queue-pixels : 0.00,0.00 {u'target': 1000, u'weight_multiplier': 0, u'smoothing': u'sqrt', u'aim': 250, u'aimed_avg': 0, u'div': 962684000, u'avg': 0, u'recent': 0} Nov 27 09:43:41 tmartitz-pc xpra[1807]: 2018-11-27 09:43:41,704 update_batch_delay: focus : 1.00,0.00 {'has_focus': False} Nov 27 09:43:41 tmartitz-pc xpra[1807]: 2018-11-27 09:43:41,704 update_batch_delay: override-redirect : 1.00,0.00 {'is_OR': False} Nov 27 09:43:41 tmartitz-pc xpra[1807]: 2018-11-27 09:43:41,704 update_batch_delay: fullscreen : 4.00,1.00 {'other_is_fullscreen': True} Nov 27 09:43:41 tmartitz-pc xpra[1807]: 2018-11-27 09:43:41,704 update_batch_delay: maximized : 0.00,0.00 {'other_is_maximized': False} Nov 27 09:43:41 tmartitz-pc xpra[1807]: 2018-11-27 09:43:41,704 update_batch_delay: soft-expired : 0.00,0.00 {'count': 0} Nov 27 09:43:41 tmartitz-pc xpra[1807]: 2018-11-27 09:43:41,704 update_batch_delay: delay=120
The last line "delay=120" seems set the high delay. Following that the delay becomes even larger. Does that makes any sense to you?
What I find also curious is that the logs output recalculations messages every second, but the log lines state "last update 20 seconds ago."
BTW: As of now, only one of the windows is affected. This is confirmed by the logs (the delay for wid=2 is small).
I see some more curious thing: For wid=1 (the problematic one) I only find references to the pixel dimensions 74x18. This is nowhere near the actual size of the window which is more like 1200x600 (roughly). On the other hand, for the working window there are multiple pixel dimensions mentioned, one of them (1920x1200) is the actual size of the window.
As expected, this has nothing to do with input lag. The batch delay goes up because you are forwarding multiple windows and one of them is fullscreen. When that happens the system decides to slow down the other windows since the fullscreen window takes priority. r21115 reduces the impact that this factor has on the batch delay. You can try applying it by hand.
Okay. That raises two questions:
1) Did anything change in this regard? In the past the full screen window was laggy as well, not any better than the other windows. It doesn't appear to be the case currently but xpra was updated a few times since then (I'm now on 2.4.2).
2) Why are the other windows slowed down at all? Is there some contention that requires a resultion like this? Since this is a local connection there ought to be enough room for many windows. Is this decision made regardless of bandwidth, cpu usage or other factors?
In my eyes slowing things down should only happen if there is a bottleneck.
Also: the fullscreen window is a terminal (terminator) which I'd like to use without window decorations, not a demanding game or anything like that. It doesn't seem appropriate to slow other windows down in favor of that even if there was a bottleneck.
Did anything change in this regard? In the past the full screen window was laggy as well, not any better than the other windows. It doesn't appear to be the case currently but xpra was updated a few times since then (I'm now on 2.4.2).
Impossible to say: there were likely many bugfixes between whatever version you had and 2.4.2
Since this is a local connection there ought to be enough room for many windows.
Even on a local connection, it is possible for screen updates to accumulate to the point where we need to slow things down a little. The newer rate control mechanisms (#2061 and earlier fixes) ought to be able to handle those sorts of problems a lot better, so this old code may be removed or at least moderated: more improvements recorded in ticket:2061#comment:4.
Why are the other windows slowed down at all? It doesn't seem appropriate to slow other windows down in favor of that even if there was a bottleneck.
The idea is to favour the window that is likely to be the one that is in use / seen. (ie: focused)
Please try latest trunk and let me know if I can close this ticket.
The situation is definitely vastly improved. I wouldn't say that anywhere near non-xpra windows but I can live with it.
I also found that for some reason KDE is setting the terminal application to full screen. I can undo that and maximize normally after starting it, which seems to help a bit also.
Should be even better now, assuming no bottleneck or even recovering from network congestion: ticket:2022#comment:76.
I see only batch delay below 10 now. I guess that's a good sign?
The latency graph in the session info doesn't show the blue batch delay line anymore. I'm on 2.5-20190109r21303-1 (xpra beta)
I see only batch delay below 10 now. I guess that's a good sign?
Where?
The latency graph in the session info doesn't show the blue batch delay line anymore. I'm on 2.5-20190109r21303-1 (xpra beta)
Thanks for reminding me, this needed fixing, done in r21340. Note that the value shown is now more "correct" with new servers - it may be lower or higher than before depending on the window size (the old value was normalized to 1 megapixel)
@kugel: can we close this ticket?
If not, please attach your server's -d stats
output.
Is it worth hanging on a week or two for me to do some testing? Away from home at the moment but back in a few days ...
Is it worth hanging on a week or two for me to do some testing? Away from home at the moment but back in a few days ...
Ping.
Well, I've just tried the latest beta (r21480) on my little netbook (cheap SoC based thing) and it seems much the same. The new thing, unfortunately, is the server keeps crashing with nothing in the log file. I'll open other tickets as and when. Will test for local connection latency issues on other machines as well - I wonder whether something is CPU bound on that cheap machine (top doesn't show CPU maxed out, but who knows..)
Interestingly just tested on my "X terminal" - cheap SoC-based settop box / NUC-alike PC and performance is much better there - not quite as good as native, but pretty close. And no crashes that I could trigger, despite what should be identical software config. So I may need to go looking for differences and crash causes.
I have one more box to test on..
The new thing, unfortunately, is the server keeps crashing with nothing in the log file.
What distro version are you running? Check the usual culprits: disable codecs and clipboard, etc.
There are no changes in 2.5 that would be likely to cause crashes like these.
Can I close this for 2.5?
As far as I can tell everything's looking pretty good here.. I'm still mostly testing r21480, I know you had some concern about ethernet performance on more recent revisions. I did upgrade the netbook (client) yesterday and things did seemed fine over ethernet there. Forcing RGB encoding definitely helps with latency...
Thanks, let's close this, we can re-open or link back here if we hit any regressions.
From IRC:
--av-sync=no
geany
window was affected, solution for that: r26627
this ticket has been moved to: https://github.com/Xpra-org/xpra/issues/1921