Skip to content
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

Windows performance profiling #9076

Open
robbkidd opened this issue Nov 7, 2019 · 8 comments

Comments

@robbkidd
Copy link
Member

@robbkidd robbkidd commented Nov 7, 2019

Where's all the IO coming from, yo?

Update this with our plan and learnings for profiling Windows performance.

@lamont-granquist

This comment has been minimized.

Copy link
Contributor

@lamont-granquist lamont-granquist commented Nov 7, 2019

So I did a bunch of work on this with simple timing on windows/unix awhile back and strace on unix. That led to:

rubygems/rubygems#2762

Which led to:

https://bugs.ruby-lang.org/issues/15856

Which led to:

chef/omnibus-software#1113

EDIT: also led to this which led to more paranoia around duplicated gem and unactivated gems:

rubygems/rubygems#2761

@lamont-granquist

This comment has been minimized.

Copy link
Contributor

@lamont-granquist lamont-granquist commented Nov 7, 2019

I also found that stat-vs-open doesn't make much of a different on either windows or unix. I don't know why ruby tends to use open rather than stat to check if a file exists, i suspect that helps with resolving complicated acl issues so that you validate that it both exists and is readable at the same time. Either way it seems to not make a difference.

@lamont-granquist

This comment has been minimized.

Copy link
Contributor

@lamont-granquist lamont-granquist commented Nov 7, 2019

And on unix what I've mostly done is just:

time /opt/chef/bin/chef-client
strace -c -f /opt/chef/bin/chef-client
strace trace=open,stat /opt/chef/bin/chef-client
@lamont-granquist

This comment has been minimized.

Copy link
Contributor

@lamont-granquist lamont-granquist commented Nov 7, 2019

And the top calls typically looks like this:

Chef Infra Client: 15.0.276
/opt/chef/bin/chef-client --version  2.43s user 0.90s system 83% cpu 4.011 total

% strace -f -c /opt/chef/bin/chef-client --version
strace: Process 44180 attached
Chef Infra Client: 15.0.276
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 47.55    0.360709           3    138777    134075 stat
 39.71    0.301194           3    105846    102814 open
  5.87    0.044508           2     18266           lstat

100,000-ish stat+open calls is typical.

So the TL;DR of fixing it looks like:

  1. investigate how to make all that I/O go away entirely
  2. investigate why that I/O is so slow on windows in particular (and maybe our way of building windows in particular?)
@lamont-granquist

This comment has been minimized.

Copy link
Contributor

@lamont-granquist lamont-granquist commented Nov 14, 2019

Using RubyInstaller 2.6.5p114 with non-appbundled chef-client binstub (chef-client --version timing):

2.96 2.98 2.91 2.88

Using RubyInstaller 2.6.5p114 with appbundled chef-client binstubs (chef-client --version timing):

3.14 3.25 3.17 3.36

@lamont-granquist

This comment has been minimized.

Copy link
Contributor

@lamont-granquist lamont-granquist commented Nov 14, 2019

Chef 15.4.45 with non-appbundled chef-client binstubs (chef-client --version timing):

4.15 4.42 4.21 4.09

Chef 15.4.45 with appbundled chef-client binstubs (chef-client --version timing):

4.27 3.98 4.14 4.23

@lamont-granquist

This comment has been minimized.

Copy link
Contributor

@lamont-granquist lamont-granquist commented Nov 14, 2019

So 22% speed improvement from using RubyInstaller over our homegrown builds (in the appbundled case)

The 30% speed improvement for the non-appbundled case may also be useful for un-appbundled knife plugins

@lamont-granquist

This comment has been minimized.

Copy link
Contributor

@lamont-granquist lamont-granquist commented Nov 15, 2019

Chef 15.5.4 performance with appbundled chef-client binstubs (chef-client --version timing):

3.77 3.62 3.56 3.91 = 3.7150 seconds

Compared to the prior 4.15500 seconds, so 10% net speedup between the -O2 to -O3 fix and the patch to ruby

@lamont-granquist lamont-granquist referenced this issue Nov 15, 2019
2 of 6 tasks complete
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
2 participants
You can’t perform that action at this time.