Specifying a timeout to a resource

[Xoph]

I'm working with @ericrlarson to implement our custom powershell_script resource. I'm now trying to set a timeout for our scripts, because one of them installs SQL, and you probably know, this can be a long-winded process. Chef hits a timeout on our resource ~30 minutes, and we are seeing SQL take longer than that sometimes.

I'm hoping you can help us figure out how to pass in the timeout from the LWRP. Here's what we ended up implementing. I think we've got the timeout being passed in correctly, but I'm not entirely convinced. Please let me know if there's anything else you need.

I've also done significant research around what might be going on here, including diving too deep for my own good into the Chef code. There was a bug in Chef 11 around the kill signal being sent for a process timeout not working, that have been fixed for Chef 12. I've tried Chef 12 (we've yet to upgrade to 12) but had no luck.

I'm also inclined to think that there could be another bug in the ShellOut code that Chef wrote. I'm not seeing how the timeout is being passed to Process.Create. The relevant code for that is also below.

Thanks in advance, Christoph GE Healthcare

---

providers\PowershellScriptEx.rb:

# Public: States that Chef WhyRun mode is supported by the LWRP
def whyrun_supported?
  true
end

# Public: Resource run action.  Executes the powershell and evaluates the result.
action :run do

    converge_by("Run #{ @new_resource }") do
        lazy_load_gems

        Chef::Log.info "Running this code: '#{ @current_resource.code }'"
        Chef::Log.info "  Working Directory: '#{ @current_resource.cwd }'"
        Dir.chdir(@current_resource.cwd)
        result = Mixlibrary::Core::Shell.windows_script_out(:powershell, @current_resource.code, {:timeout => @current_resource.timeout})
        @current_resource.exitcode = result.exitstatus

        if (0 == result.exitstatus)
            Chef::Log.warn format_script_output("#{ @new_resource } succeeded.", result.stdout) 
        elsif (@current_resource.returns.include? result.exitstatus) 
            Chef::Log.warn format_script_output("#{ @new_resource } generated a warning.", result.stdout) 
        else
            Chef::Log.error format_script_output("#{ @new_resource } failed with exit code #{ result.exitstatus }.", result.stdout) 
            raise "#{ @new_resource } failed with exit code #{ result.exitstatus }."
        end
    end
end

#Public: implements the load_current_resource method for this LWRP
def load_current_resource
    @current_resource = Chef::Resource::RstCommonPowershellscriptex.new(new_resource.name)
    @current_resource.name(new_resource.name)
    encapsulatedcode = <<-EOH
        #{new_resource.code}
    EOH
    @current_resource.code(encapsulatedcode)
    if new_resource.cwd.empty?
        @current_resource.cwd(Dir.pwd)
    else
        @current_resource.cwd(new_resource.cwd)
    end
    @current_resource.returns(new_resource.returns)
    @current_resource.exitcode = -99999
end

# Private: Loads the MixLibrary-Core component into memory. 
#          This is being done from a method to ensure that the gem is installed
#          before it is loaded into memory
def lazy_load_gems
    require 'mixlibrary/core/apps/shell'
end

# Private: Creates a message block that can easilly be seen in 
#          the Chef output stream and also makes it so we can
#          parse out the script results using a regular experession
def format_script_output(messageLine1, messageLine2)
    retval = <<-EOH

***********************************************************
************ Script Output Begin ***************
***********************************************************
#{ messageLine1 }
#{ messageLine2 }
***********************************************************
************* Script Output End ****************
***********************************************************
EOH
end

resources\PowershellScriptEx.rb:

actions :run
default_action :run 

attribute :name, :name_attribute => true
attribute :code, :kind_of => String, :default => ""
attribute :returns, :kind_of => Array, :default => []
attribute :cwd, :kind_of => String, :default => ""
attribute :timeout, :kind_of => Integer, :default => 900

attr_accessor :exitcode

Create process code from ShellOut (https://github.com/chef/mixlib-shellout/blob/master/lib/mixlib/shellout/windows.rb)

          #
          # Set cwd, environment, appname, etc.
          #
          app_name, command_line = command_to_run(self.command)
          create_process_args = {
            :app_name => app_name,
            :command_line => command_line,
            :startup_info => {
              :stdout => stdout_write,
              :stderr => stderr_write,
              :stdin => stdin_read
            },
            :environment => inherit_environment.map { |k,v| "#{k}=#{v}" },
            :close_handles => false
          }
          create_process_args[:cwd] = cwd if cwd
          # default to local account database if domain is not specified
          create_process_args[:domain] = domain.nil? ? "." : domain
          create_process_args[:with_logon] = with_logon if with_logon
          create_process_args[:password] = password if password

          #
          # Start the process
          #
          process = Process.create(create_process_args)

[carpnick]

Hey @Xoph ,

The line you were looking for in shell out code is here: https://github.com/chef/mixlib-shellout/blob/b4eb2472cbb0b18e498881c9443e26b95dd4e62f/lib/mixlib/shellout/windows.rb#L113

Regarding your request. Lets rule out the obvious pieces first. How are you converging your node? Locally? Through WINRM? Push Jobs?

The code you posted looks right. Just created this quick test myself.

 script= <<-EOF
      write-host $pwd
      sleep -seconds 60
      EOF

      procobj = Mixlibrary::Core::Shell.windows_script_out(:powershell,script, {:timeout => 10})

It died how I expected in about 10 seconds. With that said the answer to how you are executing could help.

I have a hunch you are using winrm. And you might have hit this timeout instead: https://github.com/chef/knife-windows/blob/75ba16e25c79f89c916f8f8ec80709cc2206d7c3/lib/chef/knife/winrm.rb#L187

[carpnick]

We have hit the same timeout. We had a private fix and were going to do a PR. But we hit a WinRM timeout of a hard coded 60 minutes here. https://github.com/WinRb/WinRM/pull/101

So I am working the WinRM 1.3 change into Winrm-s and then finally knife-windows before we can go over 60 minute converges. https://github.com/chef/winrm-s/issues/21

[Xoph]

We are running chef-client locally. I saw this winrm timeout, and made note of it, but I don't think it's what's affecting things, since we are running it locally.

[carpnick]

@Xoph ,

Can you try my sample powershell script in your environment and validate you get a timeout exception?

 script= <<-EOF
      write-host $pwd
      sleep -seconds 60
      EOF

      procobj = Mixlibrary::Core::Shell.windows_script_out(:powershell,script, {:timeout => 10})

[Xoph]

Just about to do that now..

[Xoph]

I do not get a timeout

[Xoph]

Nevermind, it did work, I just had something incorrect in my code.

So it's something incorrect in my implementation

[Xoph]

I logged the timeout that my PowershellScriptEx resource uses on a run, and I am seeing it is always using the default, whether I specify a timeout attribute or not.

[carpnick]

Load current resource looks like its not setting the timeout: def load_current_resource @current_resource = Chef::Resource::RstCommonPowershellscriptex.new(new_resource.name) @current_resource.name(new_resource.name) encapsulatedcode = <<-EOH

{new_resource.code}

EOH
@current_resource.code(encapsulatedcode)
if new_resource.cwd.empty?
    @current_resource.cwd(Dir.pwd)
else
    @current_resource.cwd(new_resource.cwd)
end
@current_resource.returns(new_resource.returns)
@current_resource.exitcode = -99999

enddef load_current_resource @current_resource = Chef::Resource::RstCommonPowershellscriptex.new(new_resource.name) @current_resource.name(new_resource.name) encapsulatedcode = <<-EOH

{new_resource.code}

EOH
@current_resource.code(encapsulatedcode)
if new_resource.cwd.empty?
    @current_resource.cwd(Dir.pwd)
else
    @current_resource.cwd(new_resource.cwd)
end
@current_resource.returns(new_resource.returns)
@current_resource.exitcode = -99999

end

[Xoph]

HA! That's it. Thank you for your help. First time working on creating LWRPs.