Jira (FACT-3052) Facter's gemspec globs /bin and /lib

[Josh Cooper (Jira)]

Josh Cooper moved an issue

Facter / FACT-3052 Facter's gemspec globs /bin and /lib Change By: Josh Cooper Key: PUP FACT - 11125 3052 Affects Version/s: PUP 7.7.0 Project: Puppet Facter Add Comment

This message was sent by Atlassian Jira (v8.13.2#813002-sha1:c495a97)

[Josh Cooper (Jira)]

Josh Cooper updated an issue

Facter / FACT-3052 Facter's gemspec globs /bin and /lib

Change By: Josh Cooper Priority: Normal Major

Add Comment

[Josh Cooper (Jira)]

Josh Cooper commented on FACT-3052

Re: Facter's gemspec globs /bin and /lib Passing the base directory seems to fix the problem, but that keyword argument was added in ruby 2.5 and facter 4 supports 2.3 and up. So probably need to do:   Dir[File.join(__dir__, 'bin/facter')] +  ...

Add Comment

[Josh Cooper (Jira)]

Josh Cooper updated an issue

Facter / FACT-3052

Facter's gemspec globs /bin and /lib

Change By: Josh Cooper h3. * Updated* Facter's gemspec globs "bin" and "lib" relative to the current working directory when the gem is activated. When puppet is running as a service, its cwd is "/", which results in the ruby process globbing /bin and /lib, leading to ~45k more : {noformat}[root@velvety-hybrid /]# cd /root [root@velvety-hybrid ~]# strace -fc -e newfstatat /opt/puppetlabs/puppet/bin/ruby -e 'Gem::Specification.load("/opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/specifications/facter-4.1.0.gemspec")' % time     seconds  usecs/call     calls    errors syscall ------ ----------- ----------- --------- --------- ---------------- 100.00    0.000046           0        49         1 newfstatat ------ ----------- ----------- --------- --------- ---------------- 100.00    0.000046                    49         1 total [root@velvety-hybrid ~]# cd / [root@velvety-hybrid /]# strace -fc -e newfstatat /opt/puppetlabs/puppet/bin/ruby -e 'Gem::Specification.load("/opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/specifications/facter-4.1.0.gemspec")' % time     seconds  usecs/call     calls    errors syscall ------ ----------- ----------- --------- --------- ---------------- 100.00    0.155833           3     46513         1 newfstatat ------ ----------- ----------- --------- --------- ---------------- 100.00    0.155833                 46513         1 total {noformat}   h3. *Original* * Puppet Version: 7.7.0* *OS Name/Version: CentOS 7 (with CloudLinux)* Evaluation times of maually running _puppet agent -t_ and running automatically via service are different. If manually, I see in reports total 25s and 5s for _file_ category. Via service - total 120s and 90s of them for _file_.  I made strace of puppet when running automatically and noticed that it's workdir is / and puppet somewhy recursievely reading files in all folders, for example, kernel firmware modules: {code:java} 231809 12:54:12 openat(AT_FDCWD, "lib/modules/3.10.0-962.3.2.lve1.5.28.el7.x86_64/kernel/drivers/firmware", O_RDONLY|O_CLOEXEC|O_DIRECTORY) = 12 {code} Nothing like that with manual run. When I added parameter in /usr/lib/systemd/system/puppet.service  {code:java} WorkingDirectory=/opt/puppetlabs/puppet/bin/{code} evaluation time reduced notably and became also 25s in total. *Desired Behavior:* Maybe WorkingDirectory in service file should be defined and puppet agent packaged with it?   *Actual Behavior:* My workaround is not permanent for the moment because puppet.service overwrites during puppet-agent package updates.

Add Comment

[Josh Cooper (Jira)]

Josh Cooper updated an issue

Facter / FACT-3052 Facter's gemspec globs /bin and /lib Change By: Josh Cooper

h3. *Updated* Facter's gemspec globs "bin" and "lib" relative to the current working directory when the gem is activated. When puppet is running as a service, its cwd is "/", which results in the ruby process globbing /bin and /lib, leading to ~45k more :

{noformat}[root@velvety-hybrid / ~ ]# cd /root / [root@velvety-hybrid ~]# strace -fc -e newfstatat trace=file /opt/puppetlabs/puppet/bin/ruby -e 'Gem::Specification.load("/opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/specifications/facter-4.1.0.gemspec")'

% time     seconds  usecs/call     calls    errors syscall ------ ----------- ----------- --------- --------- ----------------

100 46 . 00 75     0. 000046 000252            0        414           lstat 36.36    0.000196           0       348       198 open 10.20    0.000055           0       111         5 stat   6.12    0.000033           0         49         1 newfstatat   0.56    0.000003           0         9         5 openat   0.00    0.000000           0         1         1 access   0.00    0.000000           0         1           execve

------ ----------- ----------- --------- --------- ----------------

100.00    0. 000046                    49         1 000539                   933       210 total

[root@velvety-hybrid ~]# cd /

[root@velvety-hybrid /]# strace -fc -e newfstatat trace=file /opt/puppetlabs/puppet/bin/ruby -e 'Gem::Specification.load("/opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/specifications/facter-4.1.0.gemspec")'

% time     seconds  usecs/call     calls    errors syscall ------ ----------- ----------- --------- --------- ----------------

100 86 . 00 36     0. 155833 150082            3     46513         1 newfstatat 13.20    0.022945           3      6201         1 openat   0.20    0.000350           1       348       198 open   0.17    0.000304           0       414           lstat   0.07    0.000114           1       111         5 stat   0.00    0.000000           0         1         1 access   0.00    0.000000           0         1           execve

------ ----------- ----------- --------- --------- ----------------

100.00    0. 155833                 46513         1 173795                 53589       206 total {noformat}   h3. *Original* *Puppet Version: 7.7.0*

*OS Name/Version: CentOS 7 (with CloudLinux)* Evaluation times of maually running _puppet agent -t_ and running automatically via service are different. If manually, I see in reports total 25s and 5s for _file_ category. Via service - total 120s and 90s of them for _file_.  I made strace of puppet when running automatically and noticed that it's workdir is / and puppet somewhy recursievely reading files in all folders, for example, kernel firmware modules: {code:java}231809 12:54:12 openat(AT_FDCWD, "lib/modules/3.10.0-962.3.2.lve1.5.28.el7.x86_64/kernel/drivers/firmware", O_RDONLY|O_CLOEXEC|O_DIRECTORY) = 12 {code} Nothing like that with manual run. When I added parameter in /usr/lib/systemd/system/puppet.service  {code:java}WorkingDirectory=/opt/puppetlabs/puppet/bin/{code} evaluation time reduced notably and became also 25s in total. *Desired Behavior:* Maybe WorkingDirectory in service file should be defined and puppet agent packaged with it?   *Actual Behavior:* My workaround is not permanent for the moment because puppet.service overwrites during puppet-agent package updates.

Add Comment

[Josh Cooper (Jira)]

Josh Cooper updated an issue

Facter / FACT-3052 Facter's gemspec globs /bin and /lib Change By: Josh Cooper

h3. *Updated* Facter's gemspec globs "bin" and "lib" relative to the current working directory when the gem is activated. When puppet is running as a service, its cwd is "/", which results in the ruby process globbing /bin and /lib, leading to ~ 45k 53k more file syscalls. This process repeats for each REST request, due to puppet checking to see if the msgpack feature is present : {noformat}[root@velvety-hybrid ~]# cd /root/ [root@velvety-hybrid ~]# strace -fc -e trace=file /opt/puppetlabs/puppet/bin/ruby -e 'Gem::Specification.load("/opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/specifications/facter-4.1.0.gemspec")'

% time     seconds  usecs/call     calls    errors syscall ------ ----------- ----------- --------- --------- ----------------

46.75    0.000252           0       414           lstat

36.36    0.000196           0       348       198 open 10.20    0.000055           0       111         5 stat   6.12    0.000033           0        49         1 newfstatat   0.56    0.000003           0         9         5 openat   0.00    0.000000           0         1         1 access   0.00    0.000000           0         1           execve ------ ----------- ----------- --------- --------- ----------------

100.00    0.000539                   933       210 total

[root@velvety-hybrid ~]# cd /

[root@velvety-hybrid /]# strace -fc -e trace=file /opt/puppetlabs/puppet/bin/ruby -e 'Gem::Specification.load("/opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/specifications/facter-4.1.0.gemspec")'

% time     seconds  usecs/call     calls    errors syscall ------ ----------- ----------- --------- --------- ----------------

86.36    0.150082           3     46513         1 newfstatat

13.20    0.022945           3      6201         1 openat   0.20    0.000350           1       348       198 open   0.17    0.000304           0       414           lstat   0.07    0.000114           1       111         5 stat   0.00    0.000000           0         1         1 access   0.00    0.000000           0         1           execve ------ ----------- ----------- --------- --------- ----------------

100.00    0.173795                 53589       206 total

{noformat}   h3. *Original* *Puppet Version: 7.7.0* *OS Name/Version: CentOS 7 (with CloudLinux)* Evaluation times of maually running _puppet agent -t_ and running automatically via service are different. If manually, I see in reports total 25s and 5s for _file_ category. Via service - total 120s and 90s of them for _file_.  I made strace of puppet when running automatically and noticed that it's workdir is / and puppet somewhy recursievely reading files in all folders, for example, kernel firmware modules: {code:java}231809 12:54:12 openat(AT_FDCWD, "lib/modules/3.10.0-962.3.2.lve1.5.28.el7.x86_64/kernel/drivers/firmware", O_RDONLY|O_CLOEXEC|O_DIRECTORY) = 12 {code} Nothing like that with manual run. When I added parameter in /usr/lib/systemd/system/puppet.service  {code:java}WorkingDirectory=/opt/puppetlabs/puppet/bin/{code} evaluation time reduced notably and became also 25s in total. *Desired Behavior:* Maybe WorkingDirectory in service file should be defined and puppet agent packaged with it?   *Actual Behavior:* My workaround is not permanent for the moment because puppet.service overwrites during puppet-agent package updates.

Add Comment

[Josh Cooper (Jira)]

Josh Cooper updated an issue

Facter / FACT-3052 Facter's gemspec globs /bin and /lib

Change By: Josh Cooper Team: Coremunity

Add Comment

[Josh Cooper (Jira)]

Josh Cooper updated an issue

Facter / FACT-3052 Facter's gemspec globs /bin and /lib

Change By: Josh Cooper Sprint: Platform Core KANBAN

Add Comment

[Josh Cooper (Jira)]

Josh Cooper commented on FACT-3052

Re: Facter's gemspec globs /bin and /lib Merged to main in https://github.com/puppetlabs/facter/commit/9f80962f77509d8dbea399827f330ec60b5687a9. Follow up merged in https://github.com/puppetlabs/facter/commit/1f127b1e94e89445940b8c6943fb6ef376e7193f

Add Comment

[Josh Cooper (Jira)]

Josh Cooper commented on FACT-3052

Re: Facter's gemspec globs /bin and /lib

Follow up merged in https://github.com/puppetlabs/facter/commit/02b61e390f546928057103433dfd5b61e695e1f3 and passed CI in 02b61e390f5

Add Comment

[Josh Cooper (Jira)]

Josh Cooper updated an issue

Facter / FACT-3052

Facter's gemspec globs /bin and /lib

Change By: Josh Cooper Release Notes: Bug Fix Release Notes Summary: Facter recursively scanned the "bin" and "lib" directories relative to the current working directory when it was loaded. When "puppet" runs a service, the current working directory is "/" so we were scanning all of "/lib". Now we only scan directories relative to the location of Facter's gemspec.

Add Comment