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

Refactor concurrency #17

Merged
merged 7 commits into from Aug 9, 2014

Conversation

Projects
None yet
2 participants
@tarruda
Copy link
Member

tarruda commented Aug 8, 2014

No description provided.

tarruda added some commits Jul 18, 2014

Remove thread-safety from the API
This library will no longer support calls from multiple threads in order to
avoid unnecessary overhead associated with heavy usage of locks/conditions. Now
the only thread-safe way to communicate with the API is through the push_message
method.
@justinmk

This comment has been minimized.

Copy link
Member

justinmk commented Aug 8, 2014

Just curious: is this using twisted, or you found another way?

Nice to see the timeout go, I'll update the wiki page.

@tarruda

This comment has been minimized.

Copy link
Member

tarruda commented Aug 8, 2014

Just curious: is this using twisted, or you found another way?

Not yet, I'm currently doing a major refactor and porting the concurrency model to greenlets. Support for twisted(and consequently pypy) will come in another PR

@tarruda

This comment has been minimized.

Copy link
Member

tarruda commented Aug 8, 2014

As noted, there are some serious performance issues with YouCompleteMe when opening big files(such as :help eval())

For reference, I have ran a benchmark with both the master branch and this branch after the greenlets implementation

The benchmark is simple:

  • open nvim with youcompleteme enabled
  • enter the command :help eval()
  • exit right after with `:q

Here's the python profiler results with the master branch:

         8207378 function calls (8068348 primitive calls) in 15.864 seconds

   Ordered by: internal time
   List reduced from 1253 to 30 due to restriction <30>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    90031    4.447    0.000    5.361    0.000 {method 'run' of 'pyuv.Loop' objects}
    89998    1.002    0.000    7.087    0.000 client.py:124(unpack_message)
   722032    0.705    0.000    0.705    0.000 __init__.py:1329(getEffectiveLevel)
    45218    0.659    0.000    9.047    0.000 client.py:25(wait)
   722032    0.650    0.000    1.355    0.000 __init__.py:1343(isEnabledFor)
135216/33    0.599    0.000   13.576    0.411 client.py:207(invoke_message_cb)
   180434    0.561    0.000    1.817    0.000 client.py:90(release)
   722031    0.510    0.000    1.865    0.000 __init__.py:1128(debug)
    45218    0.448    0.000    3.456    0.000 client.py:174(msgpack_rpc_request)
   180434    0.428    0.000    0.770    0.000 client.py:83(acquire)
   134778    0.399    0.000    6.063    0.000 uv_stream.py:123(_run)
   180454    0.332    0.000    0.624    0.000 threading.py:372(notify)
    45251    0.306    0.000    0.306    0.000 {method 'write' of 'pyuv.Stream' objects}
    45218    0.297    0.000    3.900    0.000 client.py:324(async_func)
    89998    0.294    0.000    7.420    0.000 client.py:162(queue_message)
    45250    0.263    0.000    0.505    0.000 uv_stream.py:76(_on_read)
   360868    0.242    0.000    0.315    0.000 threading.py:287(__exit__)
   360868    0.240    0.000    0.411    0.000 threading.py:284(__enter__)
    45251    0.222    0.000    1.794    0.000 uv_stream.py:177(write)
   180434    0.205    0.000    0.871    0.000 threading.py:399(notifyAll)
    89998    0.186    0.000    5.141    0.000 uv_stream.py:157(read)
   360868    0.171    0.000    0.171    0.000 {method '__enter__' of 'thread.lock' objects}
   135516    0.164    0.000    0.164    0.000 {hasattr}
   180463    0.147    0.000    0.231    0.000 threading.py:299(_is_owned)
   180434    0.139    0.000    0.908    0.000 client.py:95(__enter__)
    45250    0.133    0.000    0.133    0.000 client.py:41(__init__)
   180546    0.133    0.000    0.133    0.000 {method 'acquire' of 'thread.lock' objects}
   180434    0.123    0.000    1.940    0.000 client.py:98(__exit__)
    45218    0.117    0.000    0.117    0.000 client.py:12(__init__)
    45251    0.115    0.000    0.213    0.000 __init__.py:41(packb)

and here is the same for this branch:

         2980532 function calls (2886281 primitive calls) in 9.292 seconds

   Ordered by: internal time
   List reduced from 1265 to 30 due to restriction <30>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    2.595    2.595    9.293    9.293 {method 'run' of 'pyuv.Loop' objects}
       85    1.802    0.021    6.230    0.073 {method 'join' of 'str' objects}
    45250    0.640    0.000    9.204    0.000 msgpack_stream.py:21(data_cb)
   452611    0.428    0.000    0.428    0.000 __init__.py:1329(getEffectiveLevel)
   452611    0.397    0.000    0.825    0.000 __init__.py:1343(isEnabledFor)
   452608    0.355    0.000    1.180    0.000 __init__.py:1128(debug)
    45251    0.309    0.000    0.309    0.000 {method 'write' of 'pyuv.Stream' objects}
    45218    0.261    0.000    1.227    0.000 client.py:311(func)
    45061    0.201    0.000    1.619    0.000 buffer.py:45(__iter__)
   135520    0.189    0.000    0.189    0.000 {hasattr}
    45218    0.186    0.000    0.708    0.000 client.py:85(rpc_request)
    45218    0.182    0.000    8.113    0.000 client.py:51(response_cb)
 90469/33    0.172    0.000    6.696    0.203 {method 'switch' of 'greenlet.greenlet' objects}
    45251    0.159    0.000    0.606    0.000 uv_stream.py:99(send)
    45250    0.135    0.000    9.341    0.000 uv_stream.py:76(_on_read)
    45218    0.125    0.000    1.039    0.000 rpc_stream.py:21(send)
      100    0.112    0.001    0.199    0.002 {method 'sub' of '_sre.SRE_Pattern' objects}
    45251    0.109    0.000    0.205    0.000 __init__.py:41(packb)
    45251    0.105    0.000    0.916    0.000 msgpack_stream.py:16(send)
    45251    0.096    0.000    0.096    0.000 {method 'pack' of 'msgpack._packer.Packer' objects}
    45250    0.081    0.000    8.206    0.000 rpc_stream.py:32(msg_cb)
    45218    0.073    0.000    0.264    0.000 client.py:47(rpc_yielding_request)
    45251    0.070    0.000    0.177    0.000 uv_stream.py:109(write_cb)
   145107    0.068    0.000    0.088    0.000 encoder.py:37(replace)
      112    0.053    0.000    0.053    0.000 {method 'acquire' of 'thread.lock' objects}
    45250    0.042    0.000    0.042    0.000 {method 'feed' of 'msgpack._unpacker.Unpacker' objects}
    45238    0.041    0.000    0.041    0.000 {method 'pop' of 'dict' objects}
52214/52212    0.034    0.000    0.037    0.000 {isinstance}
99383/99144    0.030    0.000    0.031    0.000 {len}
    96120    0.026    0.000    0.026    0.000 {method 'append' of 'list' objects}

After the greenlets refactor, the library is showing noticeable performance gains(probably because now there's only one call to pyuv.run()), but clearly there's still room for improvement, especially when comparing upstream YouCompleteMe with my own branch:

         360825 function calls (356860 primitive calls) in 3.002 seconds

   Ordered by: internal time
   List reduced from 1252 to 30 due to restriction <30>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    2.383    2.383    3.003    3.003 {method 'run' of 'pyuv.Loop' objects}
      100    0.144    0.001    0.293    0.003 {method 'sub' of '_sre.SRE_Pattern' objects}
   145107    0.126    0.000    0.149    0.000 encoder.py:37(replace)
        8    0.071    0.009    0.075    0.009 vimsupport.py:379(BuildRequestData)
      112    0.042    0.000    0.042    0.000 {method 'acquire' of 'thread.lock' objects}
   145109    0.023    0.000    0.023    0.000 {method 'group' of '_sre.SRE_Match' objects}
       40    0.017    0.000    0.017    0.000 {method 'update' of '_hashlib.HASH' objects}
     2193    0.008    0.000    0.008    0.000 {posix.stat}
        1    0.007    0.007    0.007    0.007 base.py:20(<module>)
   202/57    0.006    0.000    0.017    0.000 sre_parse.py:379(_parse)
     2121    0.005    0.000    0.013    0.000 genericpath.py:15(exists)
        3    0.004    0.001    0.004    0.001 {method 'read' of 'file' objects}
     2948    0.004    0.000    0.005    0.000 sre_parse.py:182(__next)
       14    0.004    0.000    0.020    0.001 plugin_host.py:226(discover_runtime_directories)
   387/54    0.004    0.000    0.014    0.000 sre_compile.py:32(_compile)
      200    0.004    0.000    0.010    0.000 sre_compile.py:207(_optimize_charset)
        2    0.003    0.002    0.032    0.016 {execfile}
        2    0.003    0.002    0.005    0.003 sre_compile.py:301(_optimize_unicode)
7161/7159    0.003    0.000    0.005    0.000 {isinstance}
        1    0.003    0.003    0.003    0.003 socket.py:45(<module>)
        6    0.003    0.000    0.005    0.001 vimsupport.py:357(CurrentFiletypes)
        1    0.003    0.003    0.033    0.033 connectionpool.py:7(<module>)
     1594    0.003    0.000    0.004    0.000 posixpath.py:68(join)
        4    0.002    0.001    0.003    0.001 collections.py:288(namedtuple)
        2    0.002    0.001    0.010    0.005 __init__.py:4(<module>)
      100    0.002    0.000    0.625    0.006 msgpack_stream.py:21(data_cb)
       14    0.002    0.000    0.024    0.002 plugin_host.py:182(_get_paths)
     1636    0.002    0.000    0.003    0.000 sre_parse.py:130(__getitem__)
  2079/25    0.002    0.000    0.005    0.000 client.py:351(process_value)
      933    0.002    0.000    0.004    0.000 __init__.py:1128(debug)

@justinmk

This comment has been minimized.

Copy link
Member

justinmk commented Aug 8, 2014

Is the last profile (3.002 seconds) your nvim-enhancement YCM branch, or upstream YCM? I'm assuming pyuv comes from your branch.

@tarruda

This comment has been minimized.

Copy link
Member

tarruda commented Aug 8, 2014

Its the nvim-enchancement branch

@tarruda

This comment has been minimized.

Copy link
Member

tarruda commented Aug 8, 2014

Pyuv is libuv bindings for python, I'm using it in all branches

@justinmk

This comment has been minimized.

Copy link
Member

justinmk commented Aug 8, 2014

Right, so there isn't a profile of upstream YCM? I'm assuming it's sub-second?

@tarruda

This comment has been minimized.

Copy link
Member

tarruda commented Aug 8, 2014

the top two profiles are for upstream YCM, but all are ran with nvim. I haven't benchmarked, but upstream YCM with vim should be similar(but faster) to nvim with my YCM branch

@justinmk

This comment has been minimized.

Copy link
Member

justinmk commented Aug 8, 2014

Looks like your changes to YCM are very minimal.

Nice work!

@tarruda

This comment has been minimized.

Copy link
Member

tarruda commented Aug 8, 2014

Thanks. I know it wont have the same performance of vanilla vim with embedded python, but I still would like to reduce the python client overhead as much as possible

tarruda added some commits Aug 8, 2014

Refactor to use greenlets for concurrency
This is a major refactor to the architecture of the library:

  - Move code from client.py to msgpack_stream.py and rpc_stream.py. Now
    client.py interfaces with a "stream stack", where the top-level is
    responsible for handling the msgpack-rpc details.
  - Now the UvStream class has been refactored to provide a callback-based API
    The blocking API is now simulated in client.py.
  - Greenlets are used to handle nested requests with a synchronous API
  - The asynchronous versions of API methods have been removed(those starting
    the 'send_')

tarruda added a commit that referenced this pull request Aug 9, 2014

@tarruda tarruda merged commit 04f4811 into neovim:master Aug 9, 2014

1 check passed

continuous-integration/travis-ci The Travis CI build passed
Details

tarruda added a commit to tarruda/python-client that referenced this pull request Aug 9, 2014

Add scripts for removing log statements before publishing
Profiling this library with nvim and YouCompleteMe opening big files showed that
the log statements(mostly the 'debug' ones) were the cause of significant
performance impact, even with logging disabled at the debug level(about 3
seconds improvement on the benchmark described at neovim#17)

This commit adds a set of scripts that temporarily remove log statements in
order to publish a more optimized version to pypi

tarruda added a commit to tarruda/python-client that referenced this pull request Aug 9, 2014

Add scripts for removing log statements before publishing
Profiling this library with nvim and YouCompleteMe opening big files showed that
the log statements(mostly the 'debug' ones) were the cause of significant
performance impact, even with logging disabled at the debug level(about 3
seconds improvement on the benchmark described at neovim#17)

This commit adds a set of scripts that temporarily remove log statements in
order to publish a more optimized version to pypi.

The script used to process the python files were taken from this article:

http://dound.com/2010/02/python-logging-performance/
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment