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)
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__
?).
clone_plane
moved to #1954.
Minor saving: r21646. Newer samples:
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)
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.
this ticket has been moved to: https://github.com/Xpra-org/xpra/issues/1953