xpra icon
Bug tracker and wiki

Opened 8 months ago

Closed 3 months ago

#1953 closed enhancement (worksforme)

optimize based on new profiling

Reported by: Antoine Martin Owned by: Antoine Martin
Priority: major Milestone: 2.5
Component: core Version: 2.3.x
Keywords: Cc:

Description

Found An awesome new Python profiler: py-spy!

Server running glxspheres:

  %Own   %Total  OwnTime  TotalTime  Function (filename:line)                                                                                                                                                                                                      
200.30% 200.50%   931.7s    932.1s   untilConcludes (4/python2.7/site-packages/xpra/net/bytestreams.py:111)
 78.30% 100.00%   439.3s    465.8s   gtk_main (4/python2.7/site-packages/xpra/gtk_common/gtk_util.py:598)
  9.20%   9.30%   14.17s    14.26s   do_video_encode (4/python2.7/site-packages/xpra/server/window/window_video_source.py:1876)
  7.50%   7.70%   10.56s    10.62s   csc_image (4/python2.7/site-packages/xpra/server/window/window_video_source.py:2047)
  7.10%   7.10%    8.98s     9.04s   get_image (4/python2.7/site-packages/xpra/x11/gtk2/window_damage.py:174)
  7.10%   7.10%    7.85s     7.91s   process_damage_region (4/python2.7/site-packages/xpra/server/window/window_video_source.py:809)
  4.00%   4.00%    4.60s     4.60s   do_video_encode (4/python2.7/site-packages/xpra/server/window/window_video_source.py:1804)
  3.60%   3.60%    4.89s     4.89s   do_video_encode (4/python2.7/site-packages/xpra/server/window/window_video_source.py:1798)
  2.20%   2.20%    2.87s     2.87s   _exit (4/python2.7/site-packages/xpra/gtk_common/error.py:98)
  1.10%   1.10%    1.19s     1.19s   do_damage (4/python2.7/site-packages/xpra/server/window/window_source.py:1149)
  0.40%   0.70%   0.411s    0.695s   get_dimensions (4/python2.7/site-packages/xpra/x11/gtk2/models/core.py:411)
  0.30%   0.30%   0.038s    0.038s   update_averages (4/python2.7/site-packages/xpra/server/source/source_stats.py:99)
  0.30%   0.30%   0.083s    0.083s   do_get_property (4/python2.7/site-packages/xpra/gtk_common/gobject_util.py:32)
  0.30%   0.30%   0.020s    0.020s   get_damage_pixels (4/python2.7/site-packages/xpra/server/source/source_stats.py:91)
  0.30%   0.30%   0.295s    0.295s   get (4/python2.7/Queue.py:161)
  0.20%   0.20%   0.249s    0.249s   formatTime (4/python2.7/logging/__init__.py:430)
  0.20%   0.20%   0.045s    0.045s   queue_packet (4/python2.7/site-packages/xpra/server/source/client_connection.py:345)
  0.20%   0.20%   0.226s    0.226s   getMessage (4/python2.7/logging/__init__.py:330)
  0.20%   0.30%   0.528s    0.690s   emit (4/python2.7/logging/__init__.py:896)
  0.20%   0.20%   0.033s    0.033s   is_managed (4/python2.7/site-packages/xpra/x11/gtk2/models/model_stub.py:51)
  0.20%   0.30%   0.090s    0.180s   _contents_changed (4/python2.7/site-packages/xpra/x11/server.py:738)
  0.10%   0.10%   0.012s    0.012s   __len__ (4/python2.7/site-packages/xpra/net/compression.py:212)
  0.10%   2.80%   0.104s     2.85s   _forward_contents_changed (4/python2.7/site-packages/xpra/x11/gtk2/models/core.py:308)
  0.10%  27.90%   0.010s    38.92s   encode_loop (4/python2.7/site-packages/xpra/server/source/client_connection.py:369)
  0.10%   0.60%   0.029s    0.923s   write (4/python2.7/site-packages/xpra/net/bytestreams.py:310)
  0.10%   0.10%   0.013s    0.028s   __init__ (4/python2.7/logging/__init__.py:306)
  0.10%   0.10%   0.010s    0.010s   make_data_packet_cb (4/python2.7/site-packages/xpra/server/window/window_source.py:1568)
  0.10%   0.10%   0.005s    0.135s   damage (4/python2.7/site-packages/xpra/server/window/window_source.py:1114)
  0.10%   0.20%   0.021s    0.395s   _log (4/python2.7/logging/__init__.py:1299)
  0.10%   0.10%   0.003s    0.003s   _add_chunks_to_queue (4/python2.7/site-packages/xpra/net/protocol.py:410)
  0.10%   0.10%   0.040s    0.041s   do_video_encode (4/python2.7/site-packages/xpra/server/window/window_video_source.py:1801)
  0.10%   0.10%   0.009s    0.016s   do_send_delayed_regions (4/python2.7/site-packages/xpra/server/window/window_video_source.py:717)
  0.10%   0.10%   0.037s    0.052s   damage (4/python2.7/site-packages/xpra/server/source/windows_mixin.py:536)
  • client:
    199.40% 199.40%   68.92s    68.92s   untilConcludes (4/python2.7/site-packages/xpra/net/bytestreams.py:111)
    100.00% 100.00%   34.50s    34.50s   check_events (pyinotify.py:1208)
     87.30% 100.00%   30.57s    34.50s   gtk_main (4/python2.7/site-packages/xpra/gtk_common/gtk_util.py:598)
      7.50%   7.50%    2.03s     2.08s   paint_with_video_decoder (4/python2.7/site-packages/xpra/client/window_backing_base.py:480)
      5.10%   5.20%    1.77s     1.86s   update_planar_textures (4/python2.7/site-packages/xpra/client/gl/gl_window_backing_base.py:1086)
      2.60%   2.60%   0.694s    0.694s   clone_plane (4/python2.7/site-packages/xpra/codecs/image_wrapper.py:12)
      1.70%   1.70%   0.290s    0.290s   _exit (4/python2.7/site-packages/xpra/gtk_common/error.py:98)
      1.00%   1.00%   0.291s    0.306s   do_gl_show (4/python2.7/site-packages/xpra/client/gl/gtk_base/gtkgl_window_backing_base.py:112)
      0.60%   0.60%   0.048s    0.048s   update_planar_textures (4/python2.7/site-packages/xpra/client/gl/gl_window_backing_base.py:1077)
      0.40%   0.40%   0.208s    0.215s   do_present_fbo (4/python2.7/site-packages/xpra/client/gl/gl_window_backing_base.py:601)
      0.30%   0.30%   0.013s    0.013s   idle_add (4/python2.7/site-packages/xpra/client/gobject_client_base.py:52)
      0.20%   0.20%   0.017s    0.017s   glEnd (OpenGL/GL/exceptional.py:45)
      0.20%   0.20%   0.094s    0.094s   glBegin (OpenGL/GL/exceptional.py:40)
      0.20%   0.20%   0.008s    0.034s   put (4/python2.7/Queue.py:138)
      0.20%   0.20%   0.023s    0.024s   do_present_fbo (4/python2.7/site-packages/xpra/client/gl/gl_window_backing_base.py:664)
      0.20%   0.20%   0.025s    0.025s   do_present_fbo (4/python2.7/site-packages/xpra/client/gl/gl_window_backing_base.py:613)
      0.20%   0.20%   0.023s    0.023s   __enter__ (4/python2.7/threading.py:286)
      0.20%   0.20%   0.016s    0.016s   render_planar_update (4/python2.7/site-packages/xpra/client/gl/gl_window_backing_base.py:1112)
      0.20%   0.20%   0.008s    0.008s   _enter (4/python2.7/site-packages/xpra/gtk_common/error.py:91)
      0.20%   0.20%   0.018s    0.018s   record_decode_time (4/python2.7/site-packages/xpra/client/mixins/window_manager.py:1273)
      0.20%   0.20%   0.028s    0.035s   notify (4/python2.7/threading.py:397)
      0.10%   0.10%   0.029s    0.029s   _is_owned (4/python2.7/threading.py:303)
      0.10%   0.10%   0.008s    0.008s   rankPacking (OpenGL/images.py:76)
      0.10%   0.10%   0.020s    0.030s   render_planar_update (4/python2.7/site-packages/xpra/client/gl/gl_window_backing_base.py:1111)
      0.10%   0.10%   0.004s    0.008s   update_planar_textures (4/python2.7/site-packages/xpra/client/gl/gl_window_backing_base.py:1080)
      0.10%   0.10%   0.003s    0.003s   pixels_for_upload (4/python2.7/site-packages/xpra/client/gl/gl_window_backing_base.py:876)
      0.10%   0.10%   0.001s    0.001s   do_read_parse_thread_loop (4/python2.7/site-packages/xpra/net/protocol.py:772)
      0.10%   0.10%   0.007s    0.021s   capsget (4/python2.7/site-packages/xpra/util.py:295)
      0.10%   0.10%   0.006s    0.006s   render_planar_update (4/python2.7/site-packages/xpra/client/gl/gl_window_backing_base.py:1101)
      0.10%   0.10%   0.034s    0.034s   do_present_fbo (4/python2.7/site-packages/xpra/client/gl/gl_window_backing_base.py:609)
      0.10%   0.20%   0.008s    0.027s   gl_context (4/python2.7/site-packages/xpra/client/gl/gtk_base/gtkgl_window_backing_base.py:99)
      0.10%   0.10%   0.003s    0.003s   write_items (4/python2.7/site-packages/xpra/net/protocol.py:620)
      0.10%   0.10%   0.002s    0.002s   do_gl_show (4/python2.7/site-packages/xpra/client/gl/gtk_base/gtkgl_window_backing_base.py:110)
      0.10%   0.10%   0.002s    0.002s   check_server_echo (4/python2.7/site-packages/xpra/client/mixins/network_state.py:176)
      0.10%   0.10%   0.003s    0.024s   get (4/python2.7/Queue.py:182)
      0.10%   0.10%   0.027s    0.027s   update_planar_textures (4/python2.7/site-packages/xpra/client/gl/gl_window_backing_base.py:1087)
      0.10%   0.10%   0.016s    0.016s   put (4/python2.7/Queue.py:118)
      0.10%   0.10%   0.010s    0.010s   get (4/python2.7/Queue.py:161)
    

Which already shows some places where we spend more time than expected (ie: get_dimensions, clone_plane), or that are in the hotpath and should be optimized (__len__?).

Change History (3)

comment:1 Changed 8 months ago by Antoine Martin

Status: newassigned

clone_plane moved to #1954.

comment:2 Changed 8 months ago by Antoine Martin

Milestone: 2.42.5

comment:3 Changed 3 months ago by Antoine Martin

Resolution: worksforme
Status: assignedclosed

Minor saving: r21646.
Newer samples:

  • server:
    200.00% 200.00%   664.1s    664.1s   untilConcludes (4/python2.7/site-packages/xpra/net/bytestreams.py:123)
    100.00% 100.00%   329.8s    332.1s   gtk_main (4/python2.7/site-packages/xpra/gtk_common/gtk_util.py:672)
      0.00%   0.00%    2.03s     2.03s   webp_encode (4/python2.7/site-packages/xpra/server/picture_encode.py:33)
      0.00%   0.00%   0.531s    0.538s   get_image (4/python2.7/site-packages/xpra/x11/gtk_x11/window_damage.py:176)
      0.00%   0.00%   0.257s    0.257s   _exit (4/python2.7/site-packages/xpra/gtk_common/error.py:99)
      0.00%   0.00%   0.129s    0.129s   _is_owned (4/python2.7/threading.py:303)
      0.00%   0.00%   0.098s    0.098s   do_process_mouse_common (4/python2.7/site-packages/xpra/x11/x11_server_core.py:929)
      0.00%   0.00%   0.086s    0.096s   get_geometry (4/python2.7/site-packages/xpra/x11/models/core.py:421)
      0.00%   0.00%   0.083s    0.083s   get_current_mask (4/python2.7/site-packages/xpra/x11/server_keyboard_config.py:446)
      0.00%   0.00%   0.077s    0.077s   get (4/python2.7/site-packages/xpra/x11/models/model_stub.py:128)
      0.00%   0.00%   0.061s    0.099s   get_dimensions (4/python2.7/site-packages/xpra/x11/models/core.py:418)
      0.00%   0.00%   0.059s    0.600s   _forward_contents_changed (4/python2.7/site-packages/xpra/x11/models/core.py:310)
      0.00%   0.00%   0.054s    0.055s   get_xshm_handle (4/python2.7/site-packages/xpra/x11/gtk_x11/window_damage.py:127)
      0.00%   0.00%   0.051s    0.051s   <genexpr> (4/python2.7/site-packages/xpra/server/window/batch_delay_calculator.py:324)
      0.00%   0.00%   0.050s    0.051s   _save (4/python2.7/site-packages/PIL/ImageFile.py:501)
      0.00%   0.00%   0.050s    0.050s   <genexpr> (4/python2.7/site-packages/xpra/server/window/window_video_source.py:1300)
      0.00%   0.00%   0.049s    0.051s   _acquire_restore (4/python2.7/threading.py:298)
      0.00%   0.00%   0.048s    0.643s   do_xpra_damage_event (4/python2.7/site-packages/xpra/x11/gtk_x11/composite.py:132)
      0.00%   0.00%   0.038s    0.038s   do_damage (4/python2.7/site-packages/xpra/server/window/window_source.py:1263)
      0.00%   0.00%   0.034s    0.034s   __enter__ (4/python2.7/threading.py:286)
      0.00%   0.00%   0.032s    0.124s   do_damage (4/python2.7/site-packages/xpra/server/window/window_video_source.py:537)
      0.00%   0.00%   0.031s    0.031s   ve_clean (4/python2.7/site-packages/xpra/server/window/window_video_source.py:321)
      0.00%   0.00%   0.031s    0.031s   put (4/python2.7/Queue.py:118)
      0.00%   0.00%   0.027s    0.028s   get (4/python2.7/Queue.py:167)
      0.00%   0.00%   0.026s    0.026s   meth (4/python2.7/socket.py:228)
      0.00%   0.00%   0.025s    0.039s   _is_owned (4/python2.7/threading.py:307)
      0.00%   0.00%   0.025s    0.025s   <genexpr> (4/python2.7/site-packages/xpra/server/window/window_video_source.py:1305)
      0.00%   0.00%   0.025s    0.025s   process_packet (4/python2.7/site-packages/xpra/server/server_base.py:892)
      0.00%   0.00%   0.023s    0.023s   damaged_ratio (4/python2.7/site-packages/xpra/server/window/video_subregion.py:388)
      0.00%   0.00%   0.023s    0.023s   get (4/python2.7/Queue.py:161)
      0.00%   0.00%   0.023s    0.023s   do_get_property (4/python2.7/site-packages/xpra/gtk_common/gobject_util.py:34)
      0.00%   0.00%   0.022s    0.110s   refresh_window_area (4/python2.7/site-packages/xpra/x11/server.py:1104)
      0.00%   0.00%   0.020s    0.022s   notify (4/python2.7/threading.py:397)
    
  • client (opengl off):
    200.00% 200.00%   79.11s    79.11s   untilConcludes (4/python2.7/site-packages/xpra/net/bytestreams.py:123)
    100.00% 100.00%   39.50s    39.50s   check_events (pyinotify.py:1208)
    100.00% 100.00%   37.43s    39.50s   gtk_main (4/python2.7/site-packages/xpra/gtk_common/gtk_util.py:672)
      0.00%   0.00%   0.007s    0.033s   set (4/python2.7/threading.py:588)
      0.00%   0.00%   0.000s    0.001s   write_buffers (4/python2.7/site-packages/xpra/net/protocol.py:691)
      0.00%   0.00%   0.007s    0.007s   _note (4/python2.7/threading.py:75)
      0.00%   0.00%   0.004s    0.005s   do_expose_event (4/python2.7/site-packages/xpra/client/gtk2/gtk2_window_base.py:146)
      0.00%   0.00%   0.001s    0.015s   _process_draw (4/python2.7/site-packages/xpra/client/mixins/window_manager.py:1282)
      0.00%   0.00%   0.001s    0.001s   free_buffer (4/python2.7/site-packages/xpra/client/window_backing_base.py:309)
      0.00%   0.00%   0.000s    0.001s   rawget (4/python2.7/site-packages/xpra/util.py:288)
      0.00%   0.00%   0.001s    0.001s   next_packet (4/python2.7/site-packages/xpra/client/client_base.py:510)
      0.00%   0.00%   0.001s    0.001s   paint_backing_offset_border (4/python2.7/site-packages/xpra/client/gtk_base/gtk_client_window_base.py:1772)
      0.00%   0.00%   0.000s    0.001s   __exit__ (4/python2.7/site-packages/xpra/gtk_common/error.py:171)
      0.00%   0.00%   0.003s    0.003s   next_packet (4/python2.7/site-packages/xpra/client/client_base.py:521)
      0.00%   0.00%   0.001s    0.001s   strget (4/python2.7/site-packages/xpra/util.py:304)
      0.00%   0.00%   0.019s    0.051s   cp (4/python2.7/site-packages/xpra/client/mixins/display.py:377)
      0.00%   0.00%   0.000s    0.001s   source_has_more (4/python2.7/site-packages/xpra/net/protocol.py:352)
      0.00%   0.00%   0.001s    0.001s   after_draw_refresh (4/python2.7/site-packages/xpra/client/client_window_base.py:610)
      0.00%   0.00%   0.006s    0.006s   encode (4/python2.7/site-packages/xpra/net/protocol.py:542)
      0.00%   0.00%   0.005s    0.589s   draw_region (4/python2.7/site-packages/xpra/client/window_backing_base.py:601)
      0.00%   0.00%   0.001s    0.001s   cairo_draw_from_drawable (4/python2.7/site-packages/xpra/client/gtk2/pixmap_backing.py:192)
      0.00%   0.00%   0.001s    0.001s   write_buffers (4/python2.7/site-packages/xpra/net/protocol.py:700)
      0.00%   0.00%   0.008s    0.008s   mask_to_names (4/python2.7/site-packages/xpra/keyboard/mask.py:51)
      0.00%   0.00%   0.001s    0.005s   intget (4/python2.7/site-packages/xpra/util.py:310)
      0.00% 100.00%   0.000s    39.47s   read (4/python2.7/site-packages/xpra/net/bytestreams.py:330)
      0.00%   0.00%   0.000s    0.001s   load (4/python2.7/site-packages/PIL/ImageFile.py:262)
      0.00%   0.00%   0.002s    0.002s   next_packet (4/python2.7/site-packages/xpra/client/client_base.py:517)
      0.00%   0.00%   0.004s    0.086s   write_buffers (4/python2.7/site-packages/xpra/net/protocol.py:693)
      0.00%   0.00%   0.002s    0.002s   __init__ (4/python2.7/site-packages/xpra/x11/common.py:22)
      0.00%   0.00%   0.001s    0.001s   encode (4/python2.7/site-packages/xpra/net/protocol.py:584)
      0.00%   0.00%   0.001s    0.002s   sy (4/python2.7/site-packages/xpra/client/mixins/display.py:358)
      0.00%   0.00%   0.001s    0.085s   write_items (4/python2.7/site-packages/xpra/net/protocol.py:685)
      0.00%   0.00%   0.002s    0.019s   notifyAll (4/python2.7/threading.py:410)
      0.00%   0.00%   0.000s    0.011s   do_expose_event (4/python2.7/site-packages/xpra/client/gtk2/gtk2_window_base.py:145)
      0.00%   0.00%   0.000s    0.001s   paint_image (4/python2.7/site-packages/xpra/client/window_backing_base.py:270)
    

I don't see anything surprising here, no obvious wastage.

Note: See TracTickets for help on using tickets.