(FACT-2793) Time limit for Facter::Core::Execute

acceptance/tests/custom_facts/time_limit_for_execute_command.rb

@@ -0,0 +1,47 @@
+test_name 'Facter::Core::Execution accepts and correctly sets a time limit option' do
+  tag 'risk:high'
+
+  first_file_content = <<-EOM
+    Facter.add(:foo) do
+      setcode do
+        Facter::Core::Execution.execute("ping 127.0.0.1", {:limit => 2})
+      end
+    end
+  EOM
+
+  second_file_content = <<-EOM
+    Facter.add(:custom_fact) do
+      setcode do
+         Facter::Core::Execution.execute("ping 127.0.0.1")
+      end
+    end
+  EOM
+
+
+  agents.each do |agent|
+
+    custom_dir = agent.tmpdir('arbitrary_dir')
+    fact_file1 = File.join(custom_dir, 'file1.rb')
+    fact_file2 = File.join(custom_dir, 'file2.rb')
+    create_remote_file(agent, fact_file1, first_file_content)
+    create_remote_file(agent, fact_file2, second_file_content)
+
+    teardown do
+      agent.rm_rf(custom_dir)
+    end
+
+    step "Facter: Logs that command of the first custom fact had timeout after setted time limit" do
+      on agent, facter('--custom-dir', custom_dir, 'foo --debug') do |facter_output|
+        assert_match(/DEBUG Facter::Core::Execution.* - Timeout encounter after 2s, killing process with pid:/,
+                     facter_output.stderr.chomp)
+      end
+    end
+
+    step "Facter: Logs that command of the second custom fact had timeout after befault time limit" do
+      on agent, facter('--custom-dir', custom_dir, 'custom_fact --debug') do |facter_output|
+        assert_match(/DEBUG Facter::Core::Execution.* - Timeout encounter after 1.5s, killing process with pid:/,
+                     facter_output.stderr.chomp)
+      end
+    end
+  end
+end

lib/facter/custom_facts/core/execution/base.rb

@@ -6,6 +6,10 @@ module Execution
       class Base
         STDERR_MESSAGE = 'Command %s resulted with the following stderr message: %s'
 
+        def initialize
+          @log = Log.new(self)
+        end
+
         # This is part of the public API. No race condition can happen
         # here because custom facts are executed sequentially
         def with_env(values)
@@ -36,9 +40,7 @@ def with_env(values)
         end
 
         def execute(command, options = {})
-          on_fail = options.fetch(:on_fail, :raise)
-          expand = options.fetch(:expand, true)
-          logger = options[:logger]
+          on_fail, expand, logger, time_limit = extract_options(options)
 
           expanded_command = if !expand && builtin_command?(command) || logger
                                command
@@ -55,11 +57,21 @@ def execute(command, options = {})
             return on_fail
           end
 
-          execute_command(expanded_command, on_fail, logger)
+          execute_command(expanded_command, on_fail, logger, time_limit)
         end
 
         private
 
+        def extract_options(options)
+          on_fail = options.fetch(:on_fail, :raise)
+          expand = options.fetch(:expand, true)
+          logger = options[:logger]
+          time_limit = options[:limit].to_i
+          time_limit = time_limit.positive? ? time_limit : nil
+
+          [on_fail, expand, logger, time_limit]
+        end
+
         def log_stderr(msg, command, logger)
           return if !msg || msg.empty?
 
@@ -77,12 +89,30 @@ def builtin_command?(command)
           output.chomp =~ /builtin/ ? true : false
         end
 
-        def execute_command(command, on_fail, logger = nil)
+        def execute_command(command, on_fail, logger = nil, time_limit = nil)
+          time_limit ||= 1.5
           begin
             # Set LC_ALL and LANG to force i18n to C for the duration of this exec;
             # this ensures that any code that parses the
             # output of the command can expect it to be in a consistent / predictable format / locale
-            out, stderr, _status_ = Open3.capture3({ 'LC_ALL' => 'C', 'LANG' => 'C' }, command.to_s)
+            opts = { 'LC_ALL' => 'C', 'LANG' => 'C' }
+            require 'timeout'
+            @log.debug("Executing command: #{command}")
+            out, stderr = Open3.popen3(opts, command.to_s) do |_, stdout, stderr, wait_thr|
+              pid = wait_thr.pid
+              output = +''
+              err = +''
+              begin
+                Timeout.timeout(time_limit) do
+                  output << stdout.read
+                  err << stderr.read
+                end
+              rescue Timeout::Error
+                @log.debug("Timeout encounter after #{time_limit}s, killing process with pid: #{pid}")
+                Process.kill('KILL', pid)
+              end
+              [output, err]
+            end
             log_stderr(stderr, command, logger)
           rescue StandardError => e
             return '' if logger

spec/custom_facts/core/execution/fact_manager_spec.rb

@@ -84,7 +84,7 @@ def handy_method
       allow(FileTest).to receive(:file?).and_return(false)
       allow(File).to receive(:executable?).with('/sbin/foo').and_return(true)
       allow(FileTest).to receive(:file?).with('/sbin/foo').and_return(true)
-      expect(Open3).to receive(:capture3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, '/sbin/foo').and_return('')
+      expect(Open3).to receive(:popen3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, '/sbin/foo').and_return('')
       executor.execute('foo')
     end
 
@@ -100,7 +100,7 @@ def handy_method
       end
 
       it 'does not expant builtin command' do
-        allow(Open3).to receive(:capture3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, '/bin/foo').and_return('')
+        allow(Open3).to receive(:popen3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, '/bin/foo').and_return('')
         allow(Open3).to receive(:capture2).with('type /bin/foo').and_return('builtin')
         executor.execute('/bin/foo', expand: false)
       end
@@ -118,7 +118,7 @@ def handy_method
       end
 
       it 'throws exception' do
-        allow(Open3).to receive(:capture3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, 'foo').and_return('')
+        allow(Open3).to receive(:popen3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, 'foo').and_return('')
         allow(Open3).to receive(:capture2).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, 'type foo').and_return('builtin')
         expect { execution_base.execute('foo', expand: false) }
           .to raise_error(ArgumentError,
@@ -131,8 +131,9 @@ def handy_method
       let(:command) { '/bin/foo' }
 
       before do
-        allow(Open3).to receive(:capture3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, command)
-                                          .and_return(['', 'some error'])
+        allow(Open3).to receive(:popen3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, command)
+                                        .and_return(['', 'some error'])
+        allow(Facter::Log).to receive(:new).with(executor).and_return(logger)
         allow(Facter::Log).to receive(:new).with('foo').and_return(logger)
 
         allow(File).to receive(:executable?).with(command).and_return(true)
@@ -163,7 +164,7 @@ def handy_method
 
     describe 'when command execution fails' do
       before do
-        allow(Open3).to receive(:capture3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, '/bin/foo').and_raise('kaboom!')
+        allow(Open3).to receive(:popen3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, '/bin/foo').and_raise('kaboom!')
         allow(File).to receive(:executable?).and_return(false)
         allow(FileTest).to receive(:file?).and_return(false)
         allow(File).to receive(:executable?).with('/bin/foo').and_return(true)
@@ -188,13 +189,13 @@ def handy_method
       end
 
       it 'returns the output of the command' do
-        allow(Open3).to receive(:capture3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, '/sbin/foo').and_return('hi')
+        allow(Open3).to receive(:popen3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, '/sbin/foo').and_return('hi')
 
         expect(executor.execute('foo')).to eq 'hi'
       end
 
       it 'strips off trailing newlines' do
-        allow(Open3).to receive(:capture3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, '/sbin/foo').and_return "hi\n"
+        allow(Open3).to receive(:popen3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, '/sbin/foo').and_return "hi\n"
 
         expect(executor.execute('foo')).to eq 'hi'
       end

spec/facter/resolvers/lsb_release_resolver_spec.rb

@@ -7,11 +7,11 @@
 
   context 'when system is ubuntu' do
     before do
-      allow(Open3).to receive(:capture3)
-        .with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, 'which lsb_release')
+      allow(Open3).to receive(:popen3)
+        .with({ 'LANG' => 'C', 'LC_ALL' => 'C' }, 'which lsb_release')
         .and_return(['/usr/bin/lsb_release', '', 0])
-      allow(Open3).to receive(:capture3)
-        .with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, 'lsb_release -a')
+      allow(Open3).to receive(:popen3)
+        .with({ 'LANG' => 'C', 'LC_ALL' => 'C' }, 'lsb_release -a')
         .and_return(["Distributor ID:\tUbuntu\nDescription:\tUbuntu 18.04.1 LTS\nRelease:\t18.04\nCodename:\tbionic\n",
                      '', 0])
     end
@@ -43,11 +43,11 @@
 
   context 'when system is centos' do
     before do
-      allow(Open3).to receive(:capture3)
-        .with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, 'which lsb_release')
+      allow(Open3).to receive(:popen3)
+        .with({ 'LANG' => 'C', 'LC_ALL' => 'C' }, 'which lsb_release')
         .and_return(['/usr/bin/lsb_release', '', 0])
-      allow(Open3).to receive(:capture3)
-        .with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, 'lsb_release -a')
+      allow(Open3).to receive(:popen3)
+        .with({ 'LANG' => 'C', 'LC_ALL' => 'C' }, 'lsb_release -a')
         .and_return([load_fixture('centos_lsb_release').read, '', 0])
     end
 
@@ -84,8 +84,8 @@
 
   context 'when lsb_release is not installed on system' do
     before do
-      allow(Open3).to receive(:capture3)
-        .with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, 'which lsb_release')
+      allow(Open3).to receive(:popen3)
+        .with({ 'LANG' => 'C', 'LC_ALL' => 'C' }, 'which lsb_release')
         .and_return(['', 'no lsb_release in (PATH:usr/sbin)', 1])
     end
 

spec/facter/resolvers/partitions_spec.rb

@@ -44,14 +44,14 @@
           .with("#{sys_block_path}/sda/sda2/size", '0').and_return('201213')
         allow(Facter::Util::FileHelper).to receive(:safe_read)
           .with("#{sys_block_path}/sda/sda1/size", '0').and_return('234')
-        allow(Open3).to receive(:capture3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, 'which blkid')
-                                          .and_return('/usr/bin/blkid')
-        allow(Open3).to receive(:capture3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, 'blkid')
-                                          .and_return(load_fixture('blkid_output').read)
-        allow(Open3).to receive(:capture3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, 'which lsblk')
-                                          .and_return('/usr/bin/lsblk')
-        allow(Open3).to receive(:capture3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, 'lsblk -fp')
-                                          .and_return(load_fixture('lsblk_output').read)
+        allow(Open3).to receive(:popen3).with({ 'LANG' => 'C', 'LC_ALL' => 'C' }, 'which blkid')
+                                        .and_return('/usr/bin/blkid')
+        allow(Open3).to receive(:popen3).with({ 'LANG' => 'C', 'LC_ALL' => 'C' }, 'blkid')
+                                        .and_return(load_fixture('blkid_output').read)
+        allow(Open3).to receive(:popen3).with({ 'LANG' => 'C', 'LC_ALL' => 'C' }, 'which lsblk')
+                                        .and_return('/usr/bin/lsblk')
+        allow(Open3).to receive(:popen3).with({ 'LANG' => 'C', 'LC_ALL' => 'C' }, 'lsblk -fp')
+                                        .and_return(load_fixture('lsblk_output').read)
       end
 
       context 'when device size files are readable' do
@@ -94,10 +94,10 @@
           .with("#{sys_block_path}/sda/dm/name").and_return('VolGroup00-LogVol00')
         allow(Facter::Util::FileHelper).to receive(:safe_read)
           .with("#{sys_block_path}/sda/size", '0').and_return('201213')
-        allow(Open3).to receive(:capture3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, 'which blkid')
-                                          .and_return('/usr/bin/blkid')
-        allow(Open3).to receive(:capture3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, 'blkid')
-                                          .and_return(load_fixture('blkid_output').read)
+        allow(Open3).to receive(:popen3).with({ 'LANG' => 'C', 'LC_ALL' => 'C' }, 'which blkid')
+                                        .and_return('/usr/bin/blkid')
+        allow(Open3).to receive(:popen3).with({ 'LANG' => 'C', 'LC_ALL' => 'C' }, 'blkid')
+                                        .and_return(load_fixture('blkid_output').read)
       end
 
       context 'when device name file is readable' do
@@ -134,10 +134,10 @@
           .with("#{sys_block_path}/sda/loop/backing_file").and_return('some_path')
         allow(Facter::Util::FileHelper).to receive(:safe_read)
           .with("#{sys_block_path}/sda/size", '0').and_return('201213')
-        allow(Open3).to receive(:capture3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, 'which blkid')
-                                          .and_return('/usr/bin/blkid')
-        allow(Open3).to receive(:capture3).with({ 'LC_ALL' => 'C', 'LANG' => 'C' }, 'blkid')
-                                          .and_return(load_fixture('blkid_output').read)
+        allow(Open3).to receive(:popen3).with({ 'LANG' => 'C', 'LC_ALL' => 'C' }, 'which blkid')
+                                        .and_return('/usr/bin/blkid')
+        allow(Open3).to receive(:popen3).with({ 'LANG' => 'C', 'LC_ALL' => 'C' }, 'blkid')
+                                        .and_return(load_fixture('blkid_output').read)
       end
 
       context 'when backing_file is readable' do