Details
Description
While using windbg to debug PUP-5768, I triggered an issue in Puppet affecting Windows that has flown under the radar based on how the code paths are exercised, but that is certainly causing performance degradations on Windows.
The problematic code was introduced in https://github.com/puppetlabs/puppet/commit/c64fa0749f673cc75c09b986f3e50a80c7237314 with the addition of calls to the Windows API GetFileAttributes. These calls were added as they were necessary to implement symlink support on Windows. When this code was introduced, we were unfortunately in the position of monkey patching broken file stats in Ruby on Windows or else write a whole new File class, replace all the calls across the codebase and hope to use it everywhere rather than the core Ruby file system. Since that was turtles all the way down, we opted to make a tiny patch to Ruby itself.
Of course, that decision had a penalty that is a bit more clear now, given the implementation of get_file_attributes has been discovered as errant. Whether this was an initial testing oversight, or a change in Ruby behavior, I'm not certain just yet.
Any time a file is stat'd, the symlink? detection codepath is triggered. Unfortunately, it would appear that paths are being fed to get_file_attributes that have forward slashes / instead of the backslashes \ that the Windows API expects. Because the symlink? code eats exceptions and returns false when the GetFileAttributes API is called at https://github.com/puppetlabs/puppet/commit/c64fa0749f673cc75c09b986f3e50a80c7237314#diff-a91b066f285a8fe7ccfa4162399d458fR162, improperly setup calls to GetFileAttributes are silently / expensively swallowed.
The net result here is that for a trivial puppet apply, I logged 925 exceptions silently swallowed (mostly Puppet looking through subdirs for code):
puppet apply -e 'notify { 'hi': }'
|
A couple of ideas come to mind on how to fix this:
- See if Ruby itself has fixed the underlying stats to support symlinks properly - re-examine if the Puppet implementation is necessary anymore on 2.1.x
- Canonicalize all paths entering the get_file_attributes code path
- Attempt to delay load the resolution if possible
The method is now called get_attributes and logging of the exceptions can be trivially added for demonstrative purposes by adding the following code at https://github.com/puppetlabs/puppet/blob/0c32e9d5e7aa87f2bcd9f8a5002c2400b6076456/lib/puppet/util/windows/file.rb#L97
open('c:/attrib-fail.txt', 'a') { |f| f << "#{file_name}\n" }}
|
An excerpt of the complete output is:
C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/gems/2.1.0/gems/bigdecimal-1.2.4/lib/puppet/indirector/resource/ral.rb
|
C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/gems/2.1.0/gems/deep_merge-1.0.1/lib/puppet/indirector/resource/ral.rb
|
C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/gems/2.1.0/gems/ffi-1.9.6-x64-mingw32/lib/puppet/indirector/resource/ral.rb
|
C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/gems/2.1.0/gems/io-console-0.4.3/lib/puppet/indirector/resource/ral.rb
|
C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/gems/2.1.0/gems/json-1.8.1/lib/puppet/indirector/resource/ral.rb
|
C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/gems/2.1.0/gems/minitar-0.5.4/lib/puppet/indirector/resource/ral.rb
|
C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/gems/2.1.0/gems/minitest-4.7.5/lib/puppet/indirector/resource/ral.rb
|
C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/gems/2.1.0/gems/psych-2.0.5/lib/puppet/indirector/resource/ral.rb
|
C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/gems/2.1.0/gems/rake-10.1.0/lib/puppet/indirector/resource/ral.rb
|
|
...
|
|
C:/ProgramData/PuppetLabs/puppet/cache/lib/puppet/type/filebucket.rb
|
C:/ProgramData/PuppetLabs/puppet/etc/csr_attributes.yaml
|
C:/ProgramData/PuppetLabs/puppet/etc/ssl/private/password
|
C:/ProgramData/PuppetLabs/puppet/etc/ssl/csr_vagrant-2008r2.pem
|
C:/ProgramData/PuppetLabs/puppet/etc/ssl/certs/vagrant-2008r2.pem
|
C:/ProgramData/PuppetLabs/puppet/etc/ssl/private_keys/vagrant-2008r2.pem
|
C:/ProgramData/PuppetLabs/puppet/etc/ssl/public_keys/vagrant-2008r2.pem
|
C:/ProgramData/PuppetLabs/puppet/cache/lib/puppet/reports/store.rb
|
C:/ProgramData/PuppetLabs/puppet/cache/reports/vagrant-2008r2/201603090411.yaml
|
Complete Log: GetFileAttributes-fails.txt