Possible regression in 3.2.5. kitchen tests failing with timeout.

[miah]

Hello,

we tried to upgrade from train 3.2.0 to train 3.2.5 and now our Kitchen tests are failing due to a timeout issue.
It looks like this:

$ bundle exec kitchen  verify --log-level debug
-----> Starting Test Kitchen (v2.3.4)
-----> Verifying <inspec-ec2>...
D      Initialize InSpec
D      Options {"backend"=>"ssh", "logger"=>#<Kitchen::Logger:0x00005615c94d1d88 @log_overwrite=true, @loggers=[#<Kitchen::Logger::LogdevLogger:0x00005615c94d1a40 @level=0, @progname="inspec-ec2", @default_formatter=#<Logger::Formatter:0x00005615c94d19f0 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x00005615c94d19a0 @shift_period_suffix=nil, @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<File:/home/test/packer/post/.kitchen/logs/inspec-ec2.log>, @mon_owner=nil, @mon_count=0, @mon_mutex=#<Thread::Mutex:0x00005615c94d1950>>>, #<Kitchen::Logger::StdoutLogger:0x00005615c94d1900 @level=0, @progname="inspec-ec2", @default_formatter=#<Logger::Formatter:0x00005615c94d18b0 @datetime_format=nil>, @formatter=#<Proc:0x00005615c94d17c0@/home/test/.gems/ruby/2.5.0/gems/test-kitchen-2.3.4/lib/kitchen/logger.rb:296>, @logdev=#<Logger::LogDevice:0x00005615c94d1860 @shift_period_suffix=nil, @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDOUT>>, @mon_owner=nil, @mon_count=0, @mon_mutex=#<Thread::Mutex:0x00005615c94d1810>>>], @logdev=#<Kitchen::Logger::LogdevLogger:0x00005615c94d1a40 @level=0, @progname="inspec-ec2", @default_formatter=#<Logger::Formatter:0x00005615c94d19f0 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x00005615c94d19a0 @shift_period_suffix=nil, @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<File:/home/test/packer/post/.kitchen/logs/inspec-ec2.log>, @mon_owner=nil, @mon_count=0, @mon_mutex=#<Thread::Mutex:0x00005615c94d1950>>>>, "sudo"=>true, "sudo_command"=>"sudo", "sudo_options"=>nil, "host"=>"ec2-xxx.compute.amazonaws.com", "port"=>22, "user"=>"admin", "keepalive"=>true, "keepalive_interval"=>60, "connection_timeout"=>15, "connection_retries"=>5, "connection_retry_sleep"=>1, "max_wait_until_ready"=>600, "compression"=>false, "compression_level"=>0, "bastion_port"=>22, "key_files"=>["/home/test/packer/post/.kitchen/inspec-ec2.pem"], "color"=>true, :controls=>nil, :backend_cache=>false}
D      [SSH] opening connection to admin@ec2-xxx.compute.amazonaws.com
D      [SSH] using options {:user_known_hosts_file=>"/dev/null", :port=>22, :compression=>false, :compression_level=>0, :keepalive=>true, :keepalive_interval=>60, :timeout=>15, :auth_methods=>["none", "publickey"], :keys_only=>true, :keys=>["/home/test/packer/post/.kitchen/inspec-ec2.pem"], :password=>"<hidden>", :forward_agent=>nil, :non_interactive=>false, :verify_host_key=>:never}
D      [SSH] admin@ec2-xxx.compute.amazonaws.com cmd = cmd.exe /c ver
D      [SSH] admin@ec2-xxx.compute.amazonaws.com cmd = Get-WmiObject Win32_OperatingSystem | Select Caption,Version | ConvertTo-Json
D      [SSH] admin@ec2-xxx.compute.amazonaws.com cmd = uname -s
D      [SSH] admin@ec2-xxx.compute.amazonaws.com cmd = uname -m
D      [SSH] admin@ec2-xxx.compute.amazonaws.com cmd = test -f /etc/debian_version && cat /etc/debian_version
D      [SSH] admin@ec2-xxx.compute.amazonaws.com cmd = test -f /etc/lsb-release && cat /etc/lsb-release
D      [SSH] admin@ec2-xxx.compute.amazonaws.com cmd = test -f /usr/bin/lsb-release && cat /usr/bin/lsb-release
D      [SSH] admin@ec2-xxx.compute.amazonaws.com cmd = test -f /etc/os-release && cat /etc/os-release
D      [SSH] admin@ec2-xxx.compute.amazonaws.com cmd = test -f /usr/bin/raspi-config
D      [SSH] admin@ec2-xxx.compute.amazonaws.com cmd = bash -c '(sudo -v) < /dev/null'
^C

and it sits there as sudo -v is actually expecting a password:

$ bundle exec kitchen login
...
$ sudo whoami
root
$ sudo -v < /dev/null

We trust you have received the usual lecture from the local System
Administrator. It usually boils down to these three things:

    #1) Respect the privacy of others.
    #2) Think before you type.
    #3) With great power comes great responsibility.

[sudo] password for admin: 
sudo: no password was provided
$ bash -c '(sudo -v) < /dev/null' 
# does the same

In Kitchen, we used to have:

suites:
- name: inspec
  verifier:
    sudo_command: sudo # <<<
    inspec_tests:
      - ../tests
    inputs: {}

Where we are overriding the default sudo command (to prevent passing -E which failed in some setup).
Setting this value back to the default one seems to be even worse (?) though:

...
D      [SSH] admin@ec2-xxx.compute.amazonaws.com cmd = test -f /usr/bin/raspi-config
D      [SSH] admin@ec2-xxx.compute.amazonaws.com cmd = bash -c '(sudo -E -v) < /dev/null'
>>>>>> ------Exception-------
>>>>>> Class: Kitchen::ActionFailed
>>>>>> Message: 1 actions failed.
>>>>>>     Failed to complete #verify action: [Sudo failed: usage: sudo -h | -K | -k | -V
usage: sudo -v [-AknS] [-g group] [-h host] [-p prompt] [-u user]
usage: sudo -l [-AknS] [-g group] [-h host] [-p prompt] [-U user] [-u user]
            [command]
usage: sudo [-AbEHknPS] [-r role] [-t type] [-C num] [-g group] [-h host] [-p
            prompt] [-T timeout] [-u user] [VAR=value] [-i|-s] [<command>]
usage: sudo -e [-AknS] [-r role] [-t type] [-C num] [-g group] [-h host] [-p
            prompt] [-T timeout] [-u user] file ...
 ] on inspec-ec2
>>>>>> ----------------------
>>>>>> Please see .kitchen/logs/kitchen.log for more details
>>>>>> Also try running `kitchen diagnose --all` for configuration

D      ------Exception-------
D      Class: Kitchen::ActionFailed
D      Message: 1 actions failed.
>>>>>>     Failed to complete #verify action: [Sudo failed ...

Originally posted by @multani in #544 (comment)

[craigmiskell-gitlab]

We've also seen:
Sudo failed: bash: -v: command not found
which I think is happening if sudo isn't required and it's evaluating to something like:
bash -c '(-v </dev/null)'

[Afterglow]

Also seeing this with straight kitchen inspec and not specifying sudo or sudo_command which defaults to true. Setting sudo to false fixes the issue. Seems related to the changes in https://github.com/inspec/train/pull/544/files. Also reported as inspec/kitchen-inspec#246.

edit: confirmed this by editing the line locally my OS (Oracle Linux 7) won't allow sudo -E -v as a valid command. Works on an ubuntu box with version 1.8.21p2-3ubuntu1.1 does not work on ol7 with 1.8.23-4.el7.x86_64

[nmaludy]

+1 seeing this too on CentOS 7

[maglo]

+1 we're seeing this too.

running against CentOS 7

bundle exec inspec shell -t <target> --sudo -i <keyfile> --chef-license=accept-silent

succeeds on train 3.1.4 but fails on 3.2.5

[myii]

As I mentioned in #544 (comment):

• https://travis-ci.com/saltstack-formulas/openvpn-formula/builds/141203737
  • 3.2.5 is only working on ubuntu-18.04 and centos-6, while failing on debian-10, amazonlinux-2, centos-7 and opensuse-leap-15.1
• Downgrading to 3.2.0 is working everywhere, in our org

[n-rodriguez]

* Downgrading to `3.2.0` is working everywhere, in our org

the same here ;)

[n-rodriguez]

It seems to come from this commit 857f776

[craigmiskell-gitlab]

Can confirm that the 3.2.14 gem version fixes this problem for my situation.

[myii]

@zenspider Thanks, this is working much better in general and many of the platforms are now working.

• https://travis-ci.org/myii/template-formula/builds/641209761

As you can see, still getting a failure on opensuse-leap-15.1, though:

• https://travis-ci.org/myii/template-formula/jobs/641209768#L1455-L1470

[myii]

Also still getting the failure with a local Vagrant FreeBSD box which works fine with 3.2.0:

-----> Verifying <v201902-py3-freebsd-120-2019-2-py3>...
>>>>>> ------Exception-------
>>>>>> Class: Kitchen::ActionFailed
>>>>>> Message: 1 actions failed.
>>>>>>     Failed to complete #verify action: [Sudo failed: We trust you have received the usual lecture from the local System
Administrator. It usually boils down to these three things:

    #1) Respect the privacy of others.
    #2) Think before you type.
    #3) With great power comes great responsibility.

sudo: a terminal is required to read the password; either use the -S option to read from standard input or configure an askpass helper] on v201902-py3-freebsd-120-2019-2-py3

[biz812]

We're seeing failures with oracle linux 7 when using 3.2.14 FWIW, HTH!

[zenspider]

@myii / @biz812 please file a separate issue per platform with reproduction steps. Thank you.