change from 'notrun' to ['0'] failed: undefined method `close!' for nil:NilClass (corrective)

[michaelday008]

I'm creating this issue because if PDK validates it, and it still fails, that seems like a bug. IMO anything that validates with PDK should not produce an error message like below.

Discussed in puppetlabs/community#72

^{Originally posted by michaelday008 May 17, 2024}
I hope this is the correct place to post this question. I have a puppet module and I can't figure out why it is failing.

Here is the relevant code that is failing. There is a bunch of other code that runs successfully before this, but I've excluded it for brevity. If I comment out the below lines, the rest of the module completes successfully:

exec { 'Sysmon':
    command => 'c:\installers\sysmon\Sysmon64.exe -accepteula -i c:\installers\sysmon\sysmonconfig-export.xml'
  }

The output I get is

C:\installers\sysmon>puppet agent -t
Info: Using environment 'production'
Info: Retrieving pluginfacts
Info: Retrieving plugin
Info: Loading facts
Notice: Requesting catalog from puppet:8140
Notice: Catalog compiled by puppet-01-dc1.prod.mydomain.ca
Info: Caching catalog for win-ad01.prod.mydomain.ca
Info: Applying configuration version '1715966702'
Error: undefined method `close!' for nil:NilClass
Error: /Stage[main]/Windows_splunk/Exec[Sysmon]/returns: change from 'notrun' to ['0'] failed: undefined method `close!' for nil:NilClass (corrective)
Notice: Applied catalog in 2.97 seconds

I know the file is there, because if I change the file path to something that doesn't exist (to troubleshoot), I get a different error:

Error: Could not find command 'c:\installers\system\Sysmon64.exe'
Error: /Stage[main]/Windows_splunk/Exec[Sysmon]/returns: change from 'notrun' to ['0'] failed: Could not find command 'c:\installers\system\Sysmon64.exe'

PDK passes with no errors:

[root@puppet-01-dc1 windows_splunk]# pdk validate
pdk (INFO): Using Ruby 3.2.3
pdk (INFO): Using Puppet 8.6.0
pdk (INFO): Running all available validators...
pdk (INFO): Validator 'puppet-plan-syntax' skipped for '/etc/puppetlabs/code/environments/production/modules/windows_splunk'. No files matching '["plans/**/*.pp"]' found to validate.
pdk (INFO): Validator 'puppet-epp' skipped for '/etc/puppetlabs/code/environments/production/modules/windows_splunk'. No files matching '["**/*.epp"]' found to validate.
pdk (INFO): Validator 'task-name' skipped for '/etc/puppetlabs/code/environments/production/modules/windows_splunk'. No files matching '["tasks/**/*"]' found to validate.
pdk (INFO): Validator 'task-metadata-lint' skipped for '/etc/puppetlabs/code/environments/production/modules/windows_splunk'. No files matching '["tasks/*.json"]' found to validate.
┌ [✔] Running metadata validators ...
├── [✔] Checking metadata syntax (metadata.json tasks/*.json).
└── [✔] Checking module metadata style (metadata.json).
┌ [✔] Running puppet validators ...
├── [✔] Checking Puppet manifest syntax (**/*.pp).
└── [✔] Checking Puppet manifest style (**/*.pp).
┌ [✔] Running ruby validators ...
└── [✔] Checking Ruby code style (**/**.rb).
┌ [✔] Running tasks validators ...
├── [✔] Checking task names (tasks/**/*).
└── [✔] Checking task metadata style (tasks/*.json).
┌ [✔] Running yaml validators ...
└── [✔] Checking YAML syntax (**/*.yaml **/*.yml).
pdk (WARNING): puppet-lint: class not documented (manifests/init.pp:1:1)
pdk (WARNING): puppet-lint: missing trailing comma after last element (manifests/init.pp:21:141)

If I run the command manually from the command line, it succeeds:

C:\installers\sysmon>c:\installers\sysmon\Sysmon64.exe -accepteula -i c:\installers\sysmon\sysmonconfig-export.xml

System Monitor v15.14 - System activity monitor
By Mark Russinovich and Thomas Garnier
Copyright (C) 2014-2024 Microsoft Corporation
Using libxml2. libxml2 is Copyright (C) 1998-2012 Daniel Veillard. All Rights Reserved.
Sysinternals - www.sysinternals.com

Loading configuration file with schema version 4.50
Sysmon schema version: 4.90
Configuration file validated.
The service Sysmon64 is already registered. Uninstall Sysmon before reinstalling.

Puppet Version:

C:\installers\sysmon>puppet --version
8.4.0

In short, I'm completely stumped because pdk validates the syntax as good syntax, but the puppet run still fails and the error message is entirely unhelpful.

[kenyon]

pdk validate only checks code syntax. Your error is occurring during the catalog application part of runtime. Correct syntax doesn't guarantee that runtime errors won't occur. Consider division by zero, for example. This would be syntactically valid, but a runtime exception.

[michaelday008]

The issue is in execute.rb on line 301

stdout.close! if Puppet::Util::Platform.windows?

This line returns a null exception if the stdout object is null. This can happen if %TEMP% is not writeable. I think the code should handle this more gracefully in one of 2 ways:

1. Perform a null reference check on stdout before attempting to run its close method.
2. Check if %TEMP% is writeable. If not, display a message that %TEMP% is not writeable.

[binford2k]

Correction, the referenced line is

puppet/lib/puppet/util/execution.rb

Line 326 in 1f3db18

stdout.close! if Puppet::Util::Platform.windows?

[joshcooper]

That's weird, stdout should never be nil, we only set it in

puppet/lib/puppet/util/execution.rb

Lines 197 to 203 in 1f3db18

	if options[:squelch]
	stdout = Puppet::FileSystem.open(null_file, nil, 'w')
	elsif Puppet.features.posix?
	reader, stdout = IO.pipe
	else
	stdout = Puppet::FileSystem::Uniquefile.new('puppet')
	end

and never reassign it. And since we do

puppet/lib/puppet/util/execution.rb

Lines 323 to 326 in 1f3db18

	unless options[:squelch]
	# if we opened a pipe, we need to clean it up.
	reader.close if reader
	stdout.close! if Puppet::Util::Platform.windows?

we know options[:squelch] is falsey and we're on Windows. So we had to have called

puppet/lib/puppet/util/execution.rb

Line 202 in 1f3db18

stdout = Puppet::FileSystem::Uniquefile.new('puppet')

Note Puppet::FIleSystem::Uniquefile does rely on environment variables to determine the tmpdir and we do check that the directory is writable (though Ruby's idea of writable files on Windows isn't accurate)

puppet/lib/puppet/file_system/uniquefile.rb

Lines 153 to 156 in 1f3db18

	[ENV.fetch('TMPDIR', nil), ENV.fetch('TMP', nil), ENV.fetch('TEMP', nil), @@systmpdir, '/tmp'].each do |dir|
	stat = File.stat(dir) if dir
	begin
	if stat && stat.directory? && stat.writable?

@michaelday008 when you say "This can happen if %TEMP% is not writeable" what is the output of icacls %TEMP% and what user are you running as? What does the following print

ruby -e "puts File.stat(ENV['TEMP']).writable?"

[michaelday008]

@joshcooper In our case %TEMP% was being set incorrectly by an RDP tool (Apache guacamole) to "c:\users\Administrator\appdata\local\temp\2".

Note the extra \2 on that end of that path. Since that folder didn't exist, the code that opens the stdout will return null since there is no folder to put the file in.

[joshcooper]

Ah I can reproduce:

C:\Users\Administrator\puppet>set TMPDIR=

C:\Users\Administrator\puppet>set TEMP="C:\Users\Administrator\AppData\Local\Temp\doesntexist"

C:\Users\Administrator\puppet>set TMP=

C:\Users\Administrator\puppet>bundle exec puppet resource exec whoami logoutput=true path="%PATH%"
Error: undefined method `close!' for nil:NilClass

        stdout.close! if Puppet::Util::Platform.windows?
              ^^^^^^^
Error: /Exec[whoami]/returns: change from 'notrun' to ['0'] failed: undefined method `close!' for nil:NilClass

        stdout.close! if Puppet::Util::Platform.windows?
              ^^^^^^^