CPU usage doesn't go idle on client when applications are idle

[totaam]

Issue migrated from trac ticket # 1362

component: client | priority: major | resolution: invalid | keywords: win32

2016-11-17 16:58:35: thomase00 created the issue

---

Client version is beta 1.0 r14228, running on Windows 7.
Server is beta 1.0 r14232 running on RHEL 6.6.

I am running a single instance of gnome-terminal on the server. CPU usage doesn't go below 5%, even when the gnome-terminal application window is totally idle and out of focus (even when minimized).

I am attaching a log generated when running the client with "-d all".

[totaam]

2016-11-17 17:10:52: thomase00 commented

---

The log reaches a steady state for a while after starting up, turning off display scaling (which I haven't figured out how to disable by default), and removing focus from the gnome-terminal window. At this point, I see the following in the log, which gets repeated many times:

poll() procinfo list: []
processing packet ping
check_server_echo(0) last=True, server_ok=True
add_packet_to_queue(ping_echo ...)
_wndproc(461562, 127, 0, 0) event name=WM_GETICON, callback=None
_wndproc(461562, 127, 0, 0) return value=119800737
_wndproc(461562, 127, 0, 0) event name=WM_GETICON, callback=None
_wndproc(461562, 127, 0, 0) return value=119800737
poll() procinfo list: []
_wndproc(461562, 127, 0, 0) event name=WM_GETICON, callback=None
_wndproc(461562, 127, 0, 0) return value=119800737
_wndproc(461562, 127, 0, 0) event name=WM_GETICON, callback=None
_wndproc(461562, 127, 0, 0) return value=119800737
poll() procinfo list: []
_wndproc(461562, 127, 0, 0) event name=WM_GETICON, callback=None
_wndproc(461562, 127, 0, 0) return value=119800737
_wndproc(461562, 127, 0, 0) event name=WM_GETICON, callback=None
_wndproc(461562, 127, 0, 0) return value=119800737
poll() procinfo list: []
_wndproc(461562, 127, 0, 0) event name=WM_GETICON, callback=None
_wndproc(461562, 127, 0, 0) return value=119800737
_wndproc(461562, 127, 0, 0) event name=WM_GETICON, callback=None
_wndproc(461562, 127, 0, 0) return value=119800737
poll() procinfo list: []
average server latency=110.6, using max wait 1.22s
add_packet_to_queue(ping ...)
processing packet ping_echo
check_server_echo(0) last=True, server_ok=True
check_server_echo(0) last=True, server_ok=True
ping echo server load=(200, 70, 10), measured client latency=109ms
_wndproc(461562, 127, 0, 0) event name=WM_GETICON, callback=None
_wndproc(461562, 127, 0, 0) return value=119800737
processing packet ping
check_server_echo(0) last=True, server_ok=True
add_packet_to_queue(ping_echo ...)
check_server_echo(1479401410801) last=True, server_ok=True
_wndproc(461562, 127, 0, 0) event name=WM_GETICON, callback=None
_wndproc(461562, 127, 0, 0) return value=119800737

It looks like maybe the client and server are just pinging each other back and forth?

At some point, I minimize the gnome-terminal window to the Windows 7 taskbar, which results in a flurry of log activity, and finally there is more log activity when I shut down the client.

[totaam]

2016-11-18 04:45:45: antoine changed owner from antoine to thomase00

[totaam]

2016-11-18 04:45:45: antoine changed component from android to client

[totaam]

2016-11-18 04:45:45: antoine commented

---

turning off display scaling (which I haven't figured out how to disable by default)
[[BR]]
See instructions on how to change "speaker" on the mailing list here: windows xpra client CPU usage and apply this to "desktop-scaling=no".

[[BR]]

I'm not sure which part of the log file corresponds to the problem.
There is a stream of:

add_packet_to_queue(configure-window ...)

Maybe that's when you were moving the window around?

Then there's a bunch of:

OnTaskbarNotify(396028, 1044, 0, 512) button(s) lookup: [(396028, 1044, 0, 512)], \
   instance=<xpra.platform.win32.win32_NotifyIcon.win32NotifyIcon object at 0x07029470>, \
   callback=<bound method Win32Tray.move_cb of <xpra.platform.win32.win32_tray.Win32Tray object at 0x07029410>>

Maybe you hovered over the systray.

If what it is printing when "nothing should be happening and the CPU is still high" is what is in comment:1, then there is nothing there that should be using the CPU at all.

Please try a different application (ie: xterm), try monitoring the network for traffic, try disabling all options, etc.. Because I'm not seeing this behaviour at all, I would notice even a 5% CPU usage.

[totaam]

2016-11-18 15:08:16: thomase00 uploaded file xpra.log (4.1 KiB)

[totaam]

2016-11-18 15:57:43: thomase00 commented

---

I generated a new log, and filtered out all of the extraneous stuff, such that it now corresponds to ~20 seconds of idle time. This is still with gnome-terminal, but I get the same behavior with xterm.

Clearly, there are keep-alive pings going over the network. I'm not sure if both the client and the server do this, or just one of them. Is it possible that there is some network IO code that polls or spins waiting for a ping (or ping-echo), rather than yielding/suspending and waiting for network activity to wake up the process?

If so, and this happens on win32 but not other platforms, it could be some idiosyncrasy related to the way network code behaves on win32.

Or, it could be that you don't notice this as much when the latency from ping to ping-echo is low. I'm running this across the continent (in USA from east coast to west coast), with pings ranging from 100ms to 200ms (i.e. MUCH longer than if the client and server are on the same LAN). As ping echo latency increases, time spent polling/spinning increases.

As an experiment, since I don't have access to a physical Linux desktop here on the east coast, I provisioned a RHEL 6.6 virtual machine on the east coast. I VNC'd into the east coast Linux VM, installed xpra, and attached to my xpra running on the west coast. I ran top, and when the xpra application windows are idle, I don't see any xpra CPU usage. So this is more evidence pointing towards it being an issue specific to the win32/Windows7 client. Again, maybe there is some network IO code that behaves differently in win32 vs. Linux (polling/spinning vs. suspended process waiting for network activity).

Also, FWIW, I'm using TCP, not SSH.

[totaam]

2016-11-18 17:01:11: thomase00 commented

---

More info and a possible solution.

I downloaded Process Explorer:

https://technet.microsoft.com/en-us/sysinternals/processexplorer.aspx

This is a nifty little tool for Windows that give you more info about running processes. It turns out that the VAST majority of CPU being used while IDLE is in a thread that seems to be associated with ig9icd32.dll, which is the Intel HD Graphics Drivers for Windows. I've attached a screenshot.

Anyway, I noticed that I had OpenGL turned off in my client settings. When I turned on OpenGL, my CPU usage dropped nearly to 0%!

Does this make sense?

[totaam]

2016-11-18 17:24:41: thomase00 commented

---

How can I get the client to have OpenGL turned on by default?

I tried editing the xpra.conf file in the directory where the client is installed (on Windows 7), but it doesn't seem to have had an effect.

-Edit:*
Nevermind, I had the beta version installed on top of the old version. The settings that I want are now in etc/xpra/conf.d/40_client.conf

[totaam]

2016-11-18 18:45:46: thomase00 commented

---

I see that OpenGL client support on Intel is grey-listed. FWIW, I have the relatively new Intel HD Graphics 530.

I haven't noticed any issues yet when using OpenGL, but when/if I do, I have the option of switching to AMD (my laptop has AMD switchable graphics).

Have you re-evaluated OpenGL on Intel with the latest hardware/drivers?

[totaam]

2016-11-18 19:30:10: thomase00 commented

---

Turning on OpenGL never occurred to me because I had assumed it had to do with the X applications themselves using OpenGL rendering (which I don't need). I have since educated myself via the Wiki. ;-)

Still, it doesn't seem that unreasonable to assume that a win32 application would use native GDI, especially if it's not doing any 3D rendering. However, it makes sense that you are using OpenGL (even for 2D stuff) if you want to minimize platform-specific code.

[totaam]

2016-11-19 05:14:16: antoine commented

---

The pings are normal, they are used to force the OS to keep the connection alive, verify that the connection is still working properly and keep track of the connection latency. I very much doubt that this is related to the problem. A ping packet every few seconds should not cause any measurable CPU, and we do use blocking sockets (so no polling involved - or at least we try to.. win32 does make this easy: #1211)

---

FYI: we use opengl rendering to save huge amounts of CPU, not to avoid using platform-specific code which the toolkit (GTK) already abstracts for us (and it uses GDI on win32).

As for why we greylist the intel driver: ClientRendering OpenGL...
We've tried to enable it by default a number of times, but had to go back on that decision because of bugs.. The current plan is to try to change the greylisted drivers to: "log a warning and enable anyway" at some point in the future. (it would be nice to be able to detect the problematic versions)
The problem is that most users will not see the warning, and they will blame xpra for crashing..

---

You should not be editing the configuration files in the Xpra installation folder, as those are the system defaults which will get overwritten whenever you install another version. I have added a wiki page about this: ClientRendering OpenGL

To make it easier to get this right, I've also added code in r14450 (+derp fixup in r14453) which will create an empty user configuration file if one does not exist yet. It will also backup the old one to prevent any confusion: r14464.

---

Finally, back to this bug: if the driver is using CPU doing nothing... I am tempted to close this bug as "invalid" - as in, we're not responsible for driver bugs and AFAIK other drivers do not waste CPU, even when using the non-opengl rendering.

[totaam]

2016-11-21 09:13:40: antoine commented

---

Please post the output of GL_check.exe and tell us if this chipset works reliably with opengl so we can use this data to update the greylist.

[totaam]

2016-11-21 14:47:35: thomase00 commented

---

The executable is called OpenGL_check.exe. Here is the output:

OpenGL_accelerate module loaded


OpenGL properties:
* GLU.extensions                  : GL_EXT_bgra
* GLU.version                     : 1.2.2.0 Microsoft Corporation
* accelerate                      : 3.1.0
* display_mode                    : DOUBLE
* extensions                      : GL_EXT_blend_minmax, GL_EXT_blend_subtract, GL_EXT_blend_color, GL_EXT_abgr, GL_EXT_texture3D, GL_EXT_clip_volume_hint, GL_EXT_compiled_vertex_array, GL_SGIS_texture_edge_clamp, GL_SGIS_generate_mipmap, GL_EXT_draw_range_elements, GL_SGIS_texture_lod, GL_EXT_rescale_normal, GL_EXT_packed_pixels, GL_EXT_texture_edge_clamp, GL_EXT_separate_specular_color, GL_ARB_multitexture, GL_ARB_map_buffer_alignment, GL_ARB_conservative_depth, GL_EXT_texture_env_combine, GL_EXT_bgra, GL_EXT_blend_func_separate, GL_EXT_secondary_color, GL_EXT_fog_coord, GL_EXT_texture_env_add, GL_ARB_texture_cube_map, GL_ARB_transpose_matrix, GL_ARB_internalformat_query, GL_ARB_internalformat_query2, GL_ARB_texture_env_add, GL_IBM_texture_mirrored_repeat, GL_ARB_texture_mirrored_repeat, GL_EXT_multi_draw_arrays, GL_SUN_multi_draw_arrays, GL_NV_blend_square, GL_ARB_texture_compression, GL_3DFX_texture_compression_FXT1, GL_EXT_texture_filter_anisotropic, GL_ARB_texture_border_clamp, GL_ARB_point_parameters, GL_ARB_texture_env_combine, GL_ARB_texture_env_dot3, GL_ARB_texture_env_crossbar, GL_EXT_texture_compression_s3tc, GL_ARB_shadow, GL_ARB_window_pos, GL_EXT_shadow_funcs, GL_EXT_stencil_wrap, GL_ARB_vertex_program, GL_EXT_texture_rectangle, GL_ARB_fragment_program, GL_EXT_stencil_two_side, GL_ATI_separate_stencil, GL_ARB_vertex_buffer_object, GL_EXT_texture_lod_bias, GL_ARB_occlusion_query, GL_ARB_fragment_shader, GL_ARB_shader_objects, GL_ARB_shading_language_100, GL_ARB_texture_non_power_of_two, GL_ARB_vertex_shader, GL_NV_texgen_reflection, GL_ARB_point_sprite, GL_ARB_fragment_program_shadow, GL_EXT_blend_equation_separate, GL_ARB_depth_texture, GL_ARB_texture_rectangle, GL_ARB_draw_buffers, GL_ARB_color_buffer_float, GL_ARB_half_float_pixel, GL_ARB_texture_float, GL_ARB_pixel_buffer_object, GL_EXT_framebuffer_object, GL_ARB_draw_instanced, GL_ARB_half_float_vertex, GL_ARB_occlusion_query2, GL_EXT_draw_buffers2, GL_WIN_swap_hint, GL_EXT_texture_sRGB, GL_ARB_multisample, GL_EXT_packed_float, GL_EXT_texture_shared_exponent, GL_ARB_texture_rg, GL_ARB_texture_compression_rgtc, GL_NV_conditional_render, GL_ARB_texture_swizzle, GL_EXT_texture_swizzle, GL_ARB_texture_gather, GL_ARB_sync, GL_ARB_cl_event, GL_ARB_framebuffer_sRGB, GL_EXT_packed_depth_stencil, GL_ARB_depth_buffer_float, GL_EXT_transform_feedback, GL_ARB_transform_feedback2, GL_ARB_draw_indirect, GL_EXT_framebuffer_blit, GL_EXT_framebuffer_multisample, GL_ARB_framebuffer_object, GL_ARB_framebuffer_no_attachments, GL_EXT_texture_array, GL_EXT_texture_integer, GL_ARB_map_buffer_range, GL_ARB_texture_buffer_range, GL_EXT_texture_snorm, GL_ARB_blend_func_extended, GL_INTEL_performance_query, GL_ARB_copy_buffer, GL_ARB_sampler_objects, GL_NV_primitive_restart, GL_ARB_seamless_cube_map, GL_ARB_seamless_cubemap_per_texture, GL_ARB_uniform_buffer_object, GL_ARB_depth_clamp, GL_ARB_vertex_array_bgra, GL_ARB_shader_bit_encoding, GL_ARB_draw_buffers_blend, GL_ARB_geometry_shader4, GL_EXT_geometry_shader4, GL_ARB_texture_query_lod, GL_ARB_explicit_attrib_location, GL_ARB_draw_elements_base_vertex, GL_EXT_shader_integer_mix, GL_ARB_instanced_arrays, GL_ARB_base_instance, GL_ARB_fragment_coord_conventions, GL_EXT_gpu_program_parameters, GL_ARB_texture_buffer_object_rgb32, GL_ARB_compatibility, GL_ARB_texture_rgb10_a2ui, GL_ARB_texture_multisample, GL_ARB_vertex_type_2_10_10_10_rev, GL_ARB_vertex_type_10f_11f_11f_rev, GL_ARB_timer_query, GL_ARB_tessellation_shader, GL_ARB_vertex_array_object, GL_ARB_provoking_vertex, GL_ARB_sample_shading, GL_ARB_texture_cube_map_array, GL_EXT_gpu_shader4, GL_ARB_gpu_shader5, GL_ARB_gpu_shader_fp64, GL_INTEL_fragment_shader_ordering, GL_ARB_fragment_shader_interlock, GL_ARB_clip_control, GL_EXT_shader_framebuffer_fetch, GL_ARB_shader_subroutine, GL_ARB_transform_feedback3, GL_ARB_get_program_binary, GL_ARB_separate_shader_objects, GL_ARB_shader_precision, GL_ARB_vertex_attrib_64bit, GL_ARB_viewport_array, GL_ARB_transform_feedback_instanced, GL_ARB_compressed_texture_pixel_storage, GL_ARB_shader_atomic_counters, GL_ARB_shading_language_packing, GL_ARB_shader_image_load_store, GL_ARB_shading_language_420pack, GL_ARB_texture_storage, GL_EXT_texture_storage, GL_ARB_compute_shader, GL_ARB_vertex_attrib_binding, GL_ARB_texture_view, GL_ARB_fragment_layer_viewport, GL_ARB_multi_draw_indirect, GL_ARB_program_interface_query, GL_ARB_shader_image_size, GL_ARB_shader_storage_buffer_object, GL_ARB_texture_storage_multisample, GL_ARB_buffer_storage, GL_AMD_vertex_shader_layer, GL_AMD_vertex_shader_viewport_index, GL_ARB_query_buffer_object, GL_EXT_polygon_offset_clamp, GL_ARB_clear_texture, GL_ARB_texture_mirror_clamp_to_edge, GL_ARB_debug_output, GL_ARB_enhanced_layouts, GL_KHR_debug, GL_ARB_arrays_of_arrays, GL_ARB_texture_query_levels, GL_ARB_invalidate_subdata, GL_ARB_clear_buffer_object, GL_AMD_depth_clamp_separate, GL_ARB_shader_stencil_export, GL_INTEL_map_texture, GL_INTEL_conservative_rasterization, GL_ARB_texture_compression_bptc, GL_ARB_ES2_compatibility, GL_ARB_ES3_compatibility, GL_ARB_robustness, GL_ARB_robust_buffer_access_behavior, GL_EXT_texture_sRGB_decode, GL_KHR_texture_compression_astc_ldr, GL_KHR_texture_compression_astc_hdr, GL_ARB_copy_image, GL_KHR_blend_equation_advanced, GL_EXT_direct_state_access, GL_ARB_stencil_texturing, GL_ARB_texture_stencil8, GL_ARB_explicit_uniform_location, GL_INTEL_multi_rate_fragment_shader, GL_ARB_multi_bind, GL_ARB_indirect_parameters, 
* gdkgl
  - version                       : 6.1
* gdkglext
  - version                       : 1.2.0
* glconfig                        : <gtk.gdkgl.Config object at 0x23dbe68 (GdkGLConfigImplWin32 at 0x2687078)>
* gtkglext
  - version                       : 1.2.0
* has_alpha                       : True
* max-viewport-dims               : (16384, 16384)
* opengl                          : 4, 4
* pygdkglext
  - version                       : 1.0.0
* pyopengl                        : 3.1.0
* renderer                        : Intel(R) HD Graphics 530
* rgba                            : True
* safe                            : False
* shading-language-version        : 4.40 - Build 20.19.15.4326
* texture-size-limit              : 16384
* transparency                    : False
* vendor                          : Intel
* zerocopy                        : True

[totaam]

2016-11-21 14:50:36: thomase00 commented

---

I guess I should just continue using it for a while and report if I have any issues. Unfortunately, I don't anticipate needing to use a wide variety of applications in the near future. Just gnome-terminal, emacs/xemacs, and occasionally firefox.

[totaam]

2016-12-26 09:22:04: antoine changed status from new to closed

[totaam]

2016-12-26 09:22:04: antoine set resolution to invalid

[totaam]

2016-12-26 09:22:04: antoine commented

---

Not heard back, closing.