Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

(maint) Encode powershell commands in file helpers #1626

Merged
merged 1 commit into from
May 15, 2020

Conversation

donoghuc
Copy link
Contributor

As far as I can tell there is some problematic path mangling with cygwin configuration on vmpooler. For example a path like C:\Windows\TEMP\install-puppet-2020-02-21_08.37.02.log is magically turned in to 'C:\cygwin64\home\Administrator\WindowsTEMPinstall-puppet-2020-02-21_08.37.02.log'. Base64 encoding the command appears to circumvent the conversion.

@donoghuc
Copy link
Contributor Author

donoghuc commented Feb 24, 2020

This PR 34b0073 appears to have broken pe-client-tools acceptance tests. https://cinext-jenkinsmaster-enterprise-prod-1.delivery.puppetlabs.net/view/Skeletor%20CI%20Goalie/job/enterprise_pe-orchestrator-client_intn-van-sys_master/16/SLAVE_LABEL=beaker,TEST_TARGET=centos7-64.mdc-windows2012r2-64client.af-centos7-64af-64af-64af,UNEEDED=UNEEDED/consoleFull

I cannot find where the path is mangled but here is what I do know:

Starting with the file_exists_on method.
We see that when the command is not encoded the Test-Path powershell command returns False

[21] pry(#<Beaker::TestCase>)> command = powershell(command)=> #<Beaker::Command:0x000055fa9372b3c8
 @append_cmds=nil,
 @args=
  ["-ExecutionPolicy Bypass",
   "-InputFormat None",
   "-NoLogo",
   "-NoProfile",
   "-NonInteractive",
   "-Command Test-Path C:\\Windows\\TEMP\\install-puppet-2020-02-24_13.17.35.log"],
 @cmdexe=false,
 @command="powershell.exe",
 @environment={},
 @options={},
 @prepend_cmds=nil>
[22] pry(#<Beaker::TestCase>)> on(host, command, { :accept_all_exit_codes => true})
    
    scanty-spectre.delivery.puppetlabs.net (windows2012r2-64-1) 13:43:36$ powershell.exe -ExecutionPolicy Bypass -InputFormat None -NoLogo -NoProfile -NonInteractive -Command Test-Path C:\Windows\TEMP\install-puppet-2020-02-24_13.17.35.log
      False
    
    scanty-spectre.delivery.puppetlabs.net (windows2012r2-64-1) executed in 0.30 seconds
=> #<Beaker::Result:0x000055fa932ff498
 @cmd=
  "powershell.exe -ExecutionPolicy Bypass -InputFormat None -NoLogo -NoProfile -NonInteractive -Command Test-Path C:\\Windows\\TEMP\\install-puppet-2020-02-24_13.17.35.log",
 @exit_code=0,
 @host="windows2012r2-64-1",
 @output="False\n",
 @raw_output="False\r\n",
 @raw_stderr="",
 @raw_stdout="False\r\n",
 @stderr="",
 @stdout="False\n">

In this case the file_exists_on method returns true because even though the command result is False the exit code is zero (maybe this is another bug????)
HOWEVER, when encoding the command we somehow trick the system in to not trying to munge the path and get:

[19] pry(#<Beaker::TestCase>)> on(host, command, { :accept_all_exit_codes => true})
    
    scanty-spectre.delivery.puppetlabs.net (windows2012r2-64-1) 13:30:19$ powershell.exe -ExecutionPolicy Bypass -InputFormat None -NoLogo -NoProfile -NonInteractive -EncodedCommand VABlAHMAdAAtAFAAYQB0AGgAIABDADoAXABXAGkAbgBkAG8AdwBzAFwAVABFAE0AUABcAGkAbgBzAHQAYQBsAGwALQBwAHUAcABwAGUAdAAtADIAMAAyADAALQAwADIALQAyADQAXwAxADMALgAxADcALgAzADUALgBsAG8AZwA=
      True
    
    scanty-spectre.delivery.puppetlabs.net (windows2012r2-64-1) executed in 0.35 seconds
=> #<Beaker::Result:0x000055fa91802848
 @cmd=
  "powershell.exe -ExecutionPolicy Bypass -InputFormat None -NoLogo -NoProfile -NonInteractive -EncodedCommand VABlAHMAdAAtAFAAYQB0AGgAIABDADoAXABXAGkAbgBkAG8AdwBzAFwAVABFAE0AUABcAGkAbgBzAHQAYQBsAGwALQBwAHUAcABwAGUAdAAtADIAMAAyADAALQAwADIALQAyADQAXwAxADMALgAxADcALgAzADUALgBsAG8AZwA=",
 @exit_code=0,
 @host="windows2012r2-64-1",
 @output="True\n",
 @raw_output="True\r\n",
 @raw_stderr="",
 @raw_stdout="True\r\n",
 @stderr="",
 @stdout="True\n">

There is a similar effect in file_contents_on except in that case the mangled path results in an exception causing my test setup https://github.com/puppetlabs/orchestrator-client/blob/3da85fc144e57eaa3901a5fa62c5cb55ae7a4054/acceptance/setup/common/pre-suite/013_install_pe-client-tools.rb#L15 to fail.

What really puzzles me is where the path mangling happens. I have traced this through all the way to Hosts#exec and i do not see where this happens. Encoding the command to prevent this seems bad if there is a case where it only works when the path is mangled. Soliciting help figuring out where this happens and how to come up with a solution that works for everybody.

@genebean
Copy link
Contributor

@trevor-vaughan Can you take a look at this?

@trevor-vaughan
Copy link
Contributor

Yeah, taking a look. I thought I had a system with cygwin in my test matrix at this point but perhaps there's some other magic happening.

@donoghuc
Copy link
Contributor Author

donoghuc commented Feb 24, 2020

@trevor-vaughan
Copy link
Contributor

@donoghuc Can you verify which versions of all of the beaker gems you're using?

@donoghuc
Copy link
Contributor Author

This shows a bit more clear the problem:

From: /home/cas/working_dir/beaker/lib/beaker/dsl/helpers/host_helpers.rb @ line 560 Beaker::DSL::Helpers::HostHelpers#file_contents_on:

    549: def file_contents_on(host, file_path)
    550:   file_contents = nil
    551: 
    552:   split_path = win_ads_path(file_path)
    553:   if file_exists_on(host, split_path[:path])
    554:     if host['platform'] =~ /windows/
    555:       file_path.gsub!('/', '\\')
    556: 
    557:       command = %{Get-Content -Raw -Path #{file_path}}
    558:       command += %{ -Stream #{split_path[:ads]}} if split_path[:ads]
    559:       require 'pry'; binding.pry
 => 560:       file_contents = on(host, powershell(command))&.stdout&.strip
    561:     else
    562:       file_contents = on(host, %(cat "#{file_path}"))&.stdout&.strip
    563:     end
    564:   else
    565:     logger.warn("File '#{file_path}' on '#{host} does not exist")
    566:   end
    567: 
    568:   return file_contents
    569: end

[4] pry(#<Beaker::TestCase>)> command
=> "Get-Content -Raw -Path C:\\Windows\\TEMP\\install-puppet-2020-02-24_15.02.40.log"
[5] pry(#<Beaker::TestCase>)> on(host, powershell(command))
    
    musical-spurt.delivery.puppetlabs.net (windows2012r2-64-1) 15:03:56$ powershell.exe -ExecutionPolicy Bypass -InputFormat None -NoLogo -NoProfile -NonInteractive -Command Get-Content -Raw -Path C:\Windows\TEMP\install-puppet-2020-02-24_15.02.40.log
      Get-Content : Cannot find path 'C:\cygwin64\home\Administrator\WindowsTEMPinsta
      ll-puppet-2020-02-24_15.02.40.log' because it does not exist.
      At line:1 char:1
      + Get-Content -Raw -Path C:WindowsTEMPinstall-puppet-2020-02-24_15.02.40.log
      + ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
          + CategoryInfo          : ObjectNotFound: (C:\cygwin64\hom...24_15.02.40.l 
         og:String) [Get-Content], ItemNotFoundException
          + FullyQualifiedErrorId : PathNotFound,Microsoft.PowerShell.Commands.GetCo 
         ntentCommand
       
    
    musical-spurt.delivery.puppetlabs.net (windows2012r2-64-1) executed in 0.38 seconds
    Exited: 1
Beaker::Host::CommandFailure: Host 'musical-spurt.delivery.puppetlabs.net' exited with 1 running:
 powershell.exe -ExecutionPolicy Bypass -InputFormat None -NoLogo -NoProfile -NonInteractive -Command Get-Content -Raw -Path C:\Windows\TEMP\install-puppet-2020-02-24_15.02.40.log
Last 10 lines of output were:
	Get-Content : Cannot find path 'C:\cygwin64\home\Administrator\WindowsTEMPinsta
	ll-puppet-2020-02-24_15.02.40.log' because it does not exist.
	At line:1 char:1
	+ Get-Content -Raw -Path C:WindowsTEMPinstall-puppet-2020-02-24_15.02.40.log
	+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
	    + CategoryInfo          : ObjectNotFound: (C:\cygwin64\hom...24_15.02.40.l 
	   og:String) [Get-Content], ItemNotFoundException
	    + FullyQualifiedErrorId : PathNotFound,Microsoft.PowerShell.Commands.GetCo 
	   ntentCommand
	 
from /home/cas/working_dir/beaker/lib/beaker/host.rb:394:in `exec'
Caused by Beaker::Host::CommandFailure: Host 'musical-spurt.delivery.puppetlabs.net' exited with 83 running:
 cmd.exe /c "C:\Windows\TEMP\install-puppet-msi-2020-02-24_15.02.40.bat"
Last 10 lines of output were:
	
	C:\cygwin64\home\Administrator>start /w msiexec.exe /i "http://builds.delivery.puppetlabs.net/pe-client-tools/332e5226db5c100fa3bf98d807e3c80fda2da0da/artifacts/windows/pe-client-tools-332e5226db5c100fa3bf98d807e3c80fda2da0da-x64.msi" /qn /L*V C:\Windows\TEMP\install-puppet-2020-02-24_15.02.40.log  
	
	C:\cygwin64\home\Administrator>exit /B 1619 
from /home/cas/working_dir/beaker/lib/beaker/host.rb:394:in `exec'

here is the encoded version:

[6] pry(#<Beaker::TestCase>)> on(host, powershell(command,'EncodedCommand' => true))
    
    musical-spurt.delivery.puppetlabs.net (windows2012r2-64-1) 15:05:42$ powershell.exe -ExecutionPolicy Bypass -InputFormat None -NoLogo -NoProfile -NonInteractive -EncodedCommand RwBlAHQALQBDAG8AbgB0AGUAbgB0ACAALQBSAGEAdwAgAC0AUABhAHQAaAAgAEMAOgBcAFcAaQBuAGQAbwB3AHMAXABUAEUATQBQAFwAaQBuAHMAdABhAGwAbAAtAHAAdQBwAHAAZQB0AC0AMgAwADIAMAAtADAAMgAtADIANABfADEANQAuADAAMgAuADQAMAAuAGwAbwBnAA==
      === Verbose logging started: 2/24/2020  23:02:40  Build type: SHIP UNICODE 5.00.9600.00  Calling process: C:\Windows\system32\msiexec.exe ===
      MSI (c) (A4:0C) [23:02:40:607]: Resetting cached policy values
      MSI (c) (A4:0C) [23:02:40:607]: Machine policy value 'Debug' is 0
      MSI (c) (A4:0C) [23:02:40:607]: ******* RunEngine:
                 ******* Product: http://builds.delivery.puppetlabs.net/pe-client-tools/332e5226db5c100fa3bf98d807e3c80fda2da0da/artifacts/windows/pe-client-tools-332e5226db5c100fa3bf98d807e3c80fda2da0da-x64.msi
                 ******* Action: 
                 ******* CommandLine: **********
      MSI (c) (A4:0C) [23:02:40:607]: Client-side and UI is none or basic: Running entire install on the server.
      MSI (c) (A4:0C) [23:02:40:607]: Grabbed execution mutex.
      MSI (c) (A4:0C) [23:02:40:623]: Cloaking enabled.
      MSI (c) (A4:0C) [23:02:40:623]: Attempting to enable all disabled privileges before calling Install on Server
      MSI (c) (A4:0C) [23:02:40:623]: Incrementing counter to disable shutdown. Counter after increment: 0
      MSI (s) (38:F8) [23:02:40:623]: Running installation inside multi-package transaction http://builds.delivery.puppetlabs.net/pe-client-tools/332e5226db5c100fa3bf98d807e3c80fda2da0da/artifacts/windows/pe-client-tools-332e5226db5c100fa3bf98d807e3c80fda2da0da-x64.msi
      MSI (s) (38:F8) [23:02:40:623]: Grabbed execution mutex.
      MSI (s) (38:50) [23:02:40:623]: Resetting cached policy values
      MSI (s) (38:50) [23:02:40:623]: Machine policy value 'Debug' is 0
      MSI (s) (38:50) [23:02:40:623]: ******* RunEngine:
                 ******* Product: http://builds.delivery.puppetlabs.net/pe-client-tools/332e5226db5c100fa3bf98d807e3c80fda2da0da/artifacts/windows/pe-client-tools-332e5226db5c100fa3bf98d807e3c80fda2da0da-x64.msi
                 ******* Action: 
                 ******* CommandLine: **********
      MSI (s) (38:50) [23:02:40:623]: File path is a URL. Downloading file. . .
      MSI (s) (38:50) [23:02:40:638]: Msi WinHttp: Performing auto proxy detection
      MSI (s) (38:50) [23:02:40:638]: MSI WinHttp: Proxy Settings Proxy: (none) | Bypass: (none) | AccessType: 0
      MSI (s) (38:50) [23:02:40:638]: StatusCode is:[404]
      MSI (s) (38:50) [23:02:40:638]: Download of URL resource http://builds.delivery.puppetlabs.net/pe-client-tools/332e5226db5c100fa3bf98d807e3c80fda2da0da/artifacts/windows/pe-client-tools-332e5226db5c100fa3bf98d807e3c80fda2da0da-x64.msi failed with last error 2
      MSI (s) (38:50) [23:02:40:638]: MainEngineThread is returning 2
      MSI (s) (38:F8) [23:02:40:638]: User policy value 'DisableRollback' is 0
      MSI (s) (38:F8) [23:02:40:638]: Machine policy value 'DisableRollback' is 0
      MSI (s) (38:F8) [23:02:40:638]: Incrementing counter to disable shutdown. Counter after increment: 0
      MSI (s) (38:F8) [23:02:40:638]: Note: 1: 1402 2: HKEY_LOCAL_MACHINE\Software\Microsoft\Windows\CurrentVersion\Installer\Rollback\Scripts 3: 2 
      MSI (s) (38:F8) [23:02:40:638]: Note: 1: 1402 2: HKEY_LOCAL_MACHINE\Software\Microsoft\Windows\CurrentVersion\Installer\Rollback\Scripts 3: 2 
      MSI (s) (38:F8) [23:02:40:638]: Decrementing counter to disable shutdown. If counter >= 0, shutdown will be denied.  Counter after decrement: -1
      MSI (c) (A4:0C) [23:02:40:638]: Decrementing counter to disable shutdown. If counter >= 0, shutdown will be denied.  Counter after decrement: -1
      MSI (c) (A4:0C) [23:02:40:638]: MainEngineThread is returning 2
      === Verbose logging stopped: 2/24/2020  23:02:40 ===

@trevor-vaughan
Copy link
Contributor

Ah....I see, that's probably getting called from beaker-puppet.

@donoghuc
Copy link
Contributor Author

@trevor-vaughan beaker 4.17.0 beaker-puppet 1.18.14

cas@cas-ThinkPad-T460p:~/working_dir/orchestrator-client/acceptance$ cat Gemfile.lock
PATH
  remote: /home/cas/working_dir/beaker
  specs:
    beaker (4.17.0)
      beaker-hostgenerator
      hocon (~> 1.0)
      in-parallel (~> 0.1)
      inifile (~> 3.0)
      minitar (~> 0.6)
      minitest (~> 5.4)
      net-scp (~> 1.2)
      net-ssh (~> 5.0)
      open_uri_redirections (~> 0.2.1)
      pry-byebug (~> 3.6)
      rb-readline (~> 0.5.3)
      rsync (~> 1.0.9)
      stringify-hash (~> 0.0)
      thor (~> 0.19)

GEM
  remote: https://artifactory.delivery.puppetlabs.net/artifactory/api/gems/rubygems/
  specs:
    ansi (1.5.0)
    ast (2.4.0)
    beaker-abs (0.5.0)
    beaker-answers (0.27.0)
      hocon (~> 1.0)
      require_all (~> 1.3.2)
      stringify-hash (~> 0.0.0)
    beaker-hostgenerator (1.2.3)
      deep_merge (~> 1.0)
      stringify-hash (~> 0.0.0)
    beaker-http (0.2.0)
      beaker (> 3.0)
      faraday (~> 0.9, >= 0.9.1)
      faraday_middleware (~> 0.9)
      json (~> 1.8)
    beaker-pe (2.11.1)
      beaker (~> 4.0)
      beaker-abs
      beaker-answers (~> 0.0)
      beaker-puppet (~> 1.0)
      beaker-vmpooler (~> 1.0)
      stringify-hash (~> 0.0.0)
    beaker-puppet (1.18.14)
      beaker (~> 4.1)
      in-parallel (~> 0.1)
      oga
      stringify-hash (~> 0.0.0)
    beaker-qa-i18n (0.0.5)
      stringify-hash (~> 0.0.0)
    beaker-vmpooler (1.3.3)
      stringify-hash (~> 0.0.0)
    byebug (11.1.1)
    coderay (1.1.2)
    deep_merge (1.2.1)
    domain_name (0.5.20190701)
      unf (>= 0.0.5, < 1.0.0)
    faraday (0.15.4)
      multipart-post (>= 1.2, < 3)
    faraday-cookie_jar (0.0.6)
      faraday (>= 0.7.4)
      http-cookie (~> 1.0.0)
    faraday_middleware (0.14.0)
      faraday (>= 0.7.4, < 1.0)
    hocon (1.3.0)
    http-cookie (1.0.3)
      domain_name (~> 0.5)
    in-parallel (0.1.17)
    inifile (3.0.0)
    json (1.8.6)
    method_source (0.9.2)
    minitar (0.9)
    minitest (5.14.0)
    multipart-post (2.1.1)
    mustache (1.0.1)
    net-ldap (0.12.1)
    net-scp (1.2.1)
      net-ssh (>= 2.6.5)
    net-ssh (5.2.0)
    oga (3.2)
      ast
      ruby-ll (~> 2.1)
    open_uri_redirections (0.2.1)
    power_assert (1.1.6)
    pry (0.12.2)
      coderay (~> 1.1.0)
      method_source (~> 0.9.0)
    pry-byebug (3.8.0)
      byebug (~> 11.0)
      pry (~> 0.10)
    rake (13.0.1)
    rb-readline (0.5.5)
    require_all (1.3.3)
    rototiller (0.1.0)
      rake (>= 0.9.0)
    rsync (1.0.9)
    ruby-ll (2.1.2)
      ansi
      ast
    scooter (4.3.4)
      beaker (>= 3.0, < 5.0)
      beaker-http (~> 0.0)
      faraday (= 0.15.4)
      faraday-cookie_jar (~> 0.0, >= 0.0.6)
      faraday_middleware (~> 0.9)
      json (~> 1.8)
      net-ldap (~> 0.6, >= 0.6.1, <= 0.12.1)
      test-unit
    stringify-hash (0.0.2)
    test-unit (3.3.5)
      power_assert
    thor (0.20.3)
    unf (0.1.4)
      unf_ext
    unf_ext (0.0.7.6)

PLATFORMS
  ruby

DEPENDENCIES
  beaker!
  beaker-abs (~> 0.4)
  beaker-hostgenerator (~> 1.1)
  beaker-pe
  beaker-puppet (~> 1.0, >= 1.0.1)
  beaker-qa-i18n (~> 0.0)
  beaker-vmpooler (~> 1.3)
  mustache (<= 1.0.1)
  rake
  rototiller (= 0.1.0)
  scooter (~> 4.0)

BUNDLED WITH
   2.1.4

@trevor-vaughan
Copy link
Contributor

@trevor-vaughan
Copy link
Contributor

I think you may be correct that system_temp_path is just wrong.

@donoghuc
Copy link
Contributor Author

I'm not sure I follow why you think https://github.com/puppetlabs/beaker-puppet/blob/master/lib/beaker-puppet/install_utils/windows_utils.rb#L54-L71 is wrong. It appears to give a valid path and the install logs are written to it (in this case:

[9] pry(#<Beaker::TestCase>)> file_path
=> "C:\\Windows\\TEMP\\install-puppet-2020-02-24_15.02.40.log"

What blows my mind is that a Command object constructed like:

From: /home/cas/working_dir/beaker/lib/beaker/dsl/wrappers.rb @ line 75 Beaker::DSL::Wrappers#powershell:

    70:           else
    71:             ps_args << "-Command #{command}"
    72:           end
    73:         end
    74: 
 => 75:         Command.new("powershell.exe", ps_args)
    76:       end
    77: 
    78:       # Convert the provided command string to Base64
    79:       # @param [String] cmd The command to convert to Base64
    80:       # @return [String] The converted string

[14] pry(#<Beaker::TestCase>)> Command.new("powershell.exe", ps_args)
=> #<Beaker::Command:0x000055a8a293ebf8
 @append_cmds=nil,
 @args=
  ["-ExecutionPolicy Bypass",
   "-InputFormat None",
   "-NoLogo",
   "-NoProfile",
   "-NonInteractive",
   "-Command Get-Content -Raw -Path C:\\Windows\\TEMP\\install-puppet-2020-02-24_15.02.40.log"],
 @cmdexe=false,
 @command="powershell.exe",
 @environment={},
 @options={},
 @prepend_cmds=nil>

in the Beaker::DSL::Helpers::HostHelpers#on method everything seems to be good:

From: /home/cas/working_dir/beaker/lib/beaker/dsl/helpers/host_helpers.rb @ line 63 Beaker::DSL::Helpers::HostHelpers#on:

    58:         # @example Using a role (defined in a Symbol) to identify the host
    59:         #   on :dashboard, "echo hello"
    60:         # @return [Result]   An object representing the outcome of *command*.
    61:         # @raise  [FailTest] Raises an exception if *command* obviously fails.
    62:         def on(host, command, opts = {}, &block)
 => 63:           block_on host, opts do | host |
    64:             if command.is_a? String
    65:               cmd_opts = {}
    66:               #add any additional environment variables to the command
    67:               if opts[:environment]
    68:                 cmd_opts['ENV'] = opts[:environment]

[19] pry(#<Beaker::TestCase>)> opts
=> {}
[20] pry(#<Beaker::TestCase>)> command
=> #<Beaker::Command:0x000055a8a289cba0
 @append_cmds=nil,
 @args=
  ["-ExecutionPolicy Bypass",
   "-InputFormat None",
   "-NoLogo",
   "-NoProfile",
   "-NonInteractive",
   "-Command Get-Content -Raw -Path C:\\Windows\\TEMP\\install-puppet-2020-02-24_15.02.40.log"],
 @cmdexe=false,
 @command="powershell.exe",
 @environment={},
 @options={},
 @prepend_cmds=nil>
[21] pry(#<Beaker::TestCase>)> host.system_temp_path
    
    musical-spurt.delivery.puppetlabs.net (windows2012r2-64-1) 15:24:11$ cmd.exe /c ECHO %SYSTEMROOT%
      C:\Windows
    
    musical-spurt.delivery.puppetlabs.net (windows2012r2-64-1) executed in 0.07 seconds
=> "C:\\Windows\\TEMP"

the command makes it all the way to the underlying call to Net::SSH without being altered by beaker.

From: /home/cas/working_dir/beaker/lib/beaker/host.rb @ line 360 Beaker::Host#exec:

    355:           @logger.with_indent do
    356:             result = connection.execute(cmdline, options, output_callback)
    357:           end
    358:         }
    359: 
 => 360:         if not options[:silent]
    361:           @logger.debug "\n#{log_prefix} executed in %0.2f seconds" % seconds
    362:         end
    363: 
    364:         if options[:reset_connection]
    365:           # Expect the connection to fail hard and possibly take a long time timeout.

[36] pry(#<Windows::Host>)> cmdline
=> "powershell.exe -ExecutionPolicy Bypass -InputFormat None -NoLogo -NoProfile -NonInteractive -Command Get-Content -Raw -Path C:\\Windows\\TEMP\\install-puppet-2020-02-24_15.02.40.log"

Maybe this is some kind of shell interpolation happening on the target? Would C:\\Windows\\TEMP\\ expand in some way?

@trevor-vaughan
Copy link
Contributor

Could cygwin itself automatically be munging the path?

@donoghuc
Copy link
Contributor Author

What i'm grasping at now is that somewhere along the line base64 encoding the command protects it from the insanity https://github.com/puppetlabs/beaker/blob/a01b5732a7d6cec146bd18d08795c64aafe1d2f1/lib/beaker/dsl/wrappers.rb#L69 . I'm going to set up a minimal example just using net-ssh against a windows target running cygwin see if I can find anything. The question on my mind is are there any systems which rely on this magical cygwin behaviour? Or would it be acceptable to obsure it with base64 encoding.

@trevor-vaughan
Copy link
Contributor

@donoghuc Well, litmus appears to have taken the EncodedCommand approach all around so it might make sense to just modify everything to go that way internally and see if that works.

@donoghuc
Copy link
Contributor Author

donoghuc commented Feb 25, 2020

OK, so yeah the interpolation appears to be on the target whenever powershell needs a path:

[44] pry(#<Windows::Host>)> c = "powershell.exe -ExecutionPolicy Bypass -InputFormat None -NoLogo -NoProfile -NonInteractive -Command Get-ChildItem C:\\Windows\\TEMP\\"
=> "powershell.exe -ExecutionPolicy Bypass -InputFormat None -NoLogo -NoProfile -NonInteractive -Command Get-ChildItem C:\\Windows\\TEMP\\"
[45] pry(#<Windows::Host>)> connection.execute(c, options, output_callback)    Get-ChildItem : Cannot find path 'C:\cygwin64\home\Administrator\WindowsTEMP' 
    because it does not exist.
    At line:1 char:1
    + Get-ChildItem C:WindowsTEMP
    + ~~~~~~~~~~~~~~~~~~~~~~~~~~~
        + CategoryInfo          : ObjectNotFound: (C:\cygwin64\hom...tor\WindowsTE 
       MP:String) [Get-ChildItem], ItemNotFoundException
        + FullyQualifiedErrorId : PathNotFound,Microsoft.PowerShell.Commands.GetCh 
       ildItemCommand
     

Interestingly it appears that it is smart enought to only do the interpolation when it expects a Path:

[48] pry(#<Windows::Host>)> c = "powershell.exe -ExecutionPolicy Bypass -InputFormat None -NoLogo -NoProfile -NonInteractive -Command Echo C:\\Windows\\TEMP\\"
=> "powershell.exe -ExecutionPolicy Bypass -InputFormat None -NoLogo -NoProfile -NonInteractive -Command Echo C:\\Windows\\TEMP\\"
[49] pry(#<Windows::Host>)> connection.execute(c, options, output_callback)    C:WindowsTEMP
=> #<Beaker::Result:0x000055a8a42edf18
 @cmd=
  "powershell.exe -ExecutionPolicy Bypass -InputFormat None -NoLogo -NoProfile -NonInteractive -Command Echo C:\\Windows\\TEMP\\",
 @exit_code=0,
 @host="windows2012r2-64-1",
 @output="C:WindowsTEMP\n",
 @raw_output="C:WindowsTEMP\r\n",
 @raw_stderr="",
 @raw_stdout="C:WindowsTEMP\r\n",
 @stderr="",
 @stdout="C:WindowsTEMP\n">

Another alternative could be to use forward slashes as path separators. That appears to trick it as well:

[46] pry(#<Windows::Host>)> c = "powershell.exe -ExecutionPolicy Bypass -InputFormat None -NoLogo -NoProfile -NonInteractive -Command Get-ChildItem C:/Windows/TEMP/"
=> "powershell.exe -ExecutionPolicy Bypass -InputFormat None -NoLogo -NoProfile -NonInteractive -Command Get-ChildItem C:/Windows/TEMP/"
[47] pry(#<Windows::Host>)> connection.execute(c, options, output_callback)    
    
        Directory: C:\Windows\TEMP
    
    
    Mode                LastWriteTime     Length Name                              
    ----                -------------     ------ ----                              
    d----         2/24/2020  10:02 PM            Crashpad                          
    d----         1/21/2020   9:37 PM            vmware-SYSTEM                  

Why do we gsub!('/','\\') all over the place for windows paths?

@trevor-vaughan
Copy link
Contributor

All versions of windows can handle \\ properly, but some don't handle mixed types or /.

@joshcooper
Copy link
Contributor

Why do we gsub!('/','\') all over the place for windows paths?

Windows APIs can generally handle back or forward slashes, but many command line utilities can't, such as cmd.exe /c type C:/foo. It fails because cmd.exe thinks '/foo' is a CLI argument, similarly for msiexec.exe 🤦‍♂. So whenever we shell out on Windows via beaker we generally prefer backslashes in file paths, at least when using the cmd-based Host object.

@trevor-vaughan
Copy link
Contributor

I seemed to also have issues with some PowerShell commands but I don't quite remember. Basically, I found that switching them worked all around so just went with it :-D

@glennsarti
Copy link
Contributor

glennsarti commented Feb 25, 2020

@glennsarti
Copy link
Contributor

The current Beaker encoding command is a bit wonky.

https://github.com/puppetlabs/beaker/blob/a01b5732a7d6cec146bd18d08795c64aafe1d2f1/lib/beaker/dsl/wrappers.rb#L78-L88

The encoded command SHOULD be a Base64 encoded UTF16LE string. As ruby internally is (probably) using UTF8 you'll see odd things. I'd suggest using:

encoded_command = Base64.strict_encode64(cmd.encode('UTF-16LE'))

As a side warning, some virus scanners see command encoding as an obfuscation technique and may block the call. This is wrong but 🤷‍♂️

if file_exists_on(host, split_path[:path])
if host['platform'] =~ /windows/
file_path.gsub!('/', '\\')

command = %{Get-Content -Raw -Path #{file_path}}
command += %{ -Stream #{split_path[:ads]}} if split_path[:ads]

file_contents = on(host, powershell(command))&.stdout&.strip
file_contents = on(host, powershell(command, 'EncodedCommand' => true))&.stdout&.strip
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Would it be worth the added complexity of only encoding the command if we can find the magic cygwin tmp path?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Well, another option is to just nail the temp directory to C:\Windows\Temp. I mean, it really doesn't matter where it is as long as it is consistent (I think).

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Though i dont know what we would search for.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah, wait, that was the native cygwin magic that was getting in the way 🤦‍♂. Litmus seems to have gone the way of always Base64 encoding so that should work across the board.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We could also just create our own directory at C:\Windows\BeakerTemp. Cygwin shouldn't mess with that.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just checked and the only call to %SYSTEMROOT% is the one in beaker/host/windows/file.rb. As long as things are using the system_temp_path function, we can set it to whatever we like.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I guess as long as you can be sure that cygwin is installed wherever you're going.

Most images do not have cygwin installed at this point.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ahh right. So your C:\Windows\BeakerTemp idea, we would try to ensure that is created? then test authors would have to ensure that it is cleaned up? I'm not sure how cleanup goes in windows for stuff under temp, but creating a new directory under C:\Windows seems like it could be problematic.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nah, directories are directories. It's cruft but beaker tears everything down at the end anyway.

Bolt would need to be careful, but beaker creates dynamically named tempfiles for everything that it runs in general anyway.

I figure that we would just see if the directory exists and create it if it doesn't. You can then bind the tempdir location into the SUT object itself so that it carries it around and just return it at every call to the function so that we don't hit the system every time.

(If anyone knows otherwise regarding the directories, please chime in!)

@donoghuc
Copy link
Contributor Author

From https://cygwin.com/cygwin-ug-net/setup-env.html:

If set, these variables will be used by some Cygwin applications, possibly with unexpected results.

Moving forward Do we just need to clean up that encode method that Glen pointed out and then 🤞 we dont get blocked by AV for obfuscation?

@highb
Copy link
Contributor

highb commented Feb 25, 2020

Jenkins, test this please

@highb
Copy link
Contributor

highb commented Feb 25, 2020

Jenkins is essentially passing now, the only failure is the very flaky IIS module test which I'm starting to think that we should stop testing, given its bad track record.

@highb
Copy link
Contributor

highb commented Mar 11, 2020

Jenkins, test this please

@trevor-vaughan
Copy link
Contributor

I'll go ahead and pull this into my tests and make sure it works there as well

@trevor-vaughan
Copy link
Contributor

No issues in my tests 👍

@donoghuc
Copy link
Contributor Author

Looking a the history this encoding https://github.com/puppetlabs/beaker/blame/master/lib/beaker/dsl/wrappers.rb#L77-L88 has been used for at least 5 years. Changing it seems somewhat risky as it could affect any consumer of the powershell host helper using the EncodeCommand option. I do think it will be easier to avoid this particular bug by encoding rather than trying to anticipate what cygwin will do.

@mcdonaldseanp
Copy link
Contributor

per Glenn's comment above, I think the concern is around the fact that windows applications are UTF16LE by default: https://docs.microsoft.com/en-us/windows/win32/intl/character-sets

Which means we send the wrong encoding with the command from beaker: it's likely ruby will be encoding it as UTF-8 (which I also think is the default for ruby).

I agree with @donoghuc that changing the encoding could be potentially risky, so I can get on-board getting this merged and watching for new windows failures.

@joshcooper
Copy link
Contributor

The original problem stems from not having enough backslashes in the command. Notice in the output from above WindowsTEMPinsta:

    musical-spurt.delivery.puppetlabs.net (windows2012r2-64-1) 15:03:56$ powershell.exe -ExecutionPolicy Bypass -InputFormat None -NoLogo -NoProfile -NonInteractive -Command Get-Content -Raw -Path C:\Windows\TEMP\install-puppet-2020-02-24_15.02.40.log
      Get-Content : Cannot find path 'C:\cygwin64\home\Administrator\WindowsTEMPinsta
      ll-puppet-2020-02-24_15.02.40.log' because it does not exist.

That's because we "lost" the backslash and powershell running in cygwin interpreted that as a relative path, so it's appended to the current working directory, which for cygwin is going to be C:\cygwin64\home\Administrator.

You can repro the issue by doing:

$ ssh [email protected] 'powershell -Command ls C:\Windows\Temp'
ls : Cannot find path 'C:\cygwin64\home\Administrator\WindowsTemp' because it does not exist.

If you add an extra level of escaping it works, because the single backslash "tunnels" through ssh.

$ ssh [email protected] 'powershell -Command ls C:\\Windows\\Temp'
    Directory: C:\Windows\Temp


Mode                LastWriteTime         Length Name
----                -------------         ------ ----
d-----        4/29/2020   4:05 PM                Crashpad
...

About the encoding issue, beaker is doing a really silly conversion from the current encoding to UTF-16LE:

   cmd = cmd.chars.to_a.join("\x00").chomp 
   cmd << "\x00" unless cmd[-1].eql? "\x00" 

It should just do:

cmd = cmd.encode('UTF-16LE')

For example, these are equivalent:

irb(main):025:0> cmd = "foo"
=> "foo"
irb(main):026:0> cmd = cmd.chars.to_a.join("\x00").chomp
=> "f\u0000o\u0000o"
irb(main):027:0> cmd << "\x00" unless cmd[-1].eql? "\x00"
=> "f\u0000o\u0000o\u0000"
irb(main):028:0> cmd.bytes
=> [102, 0, 111, 0, 111, 0]
irb(main):029:0> ("foo".encode(Encoding::UTF_16LE)).bytes
=> [102, 0, 111, 0, 111, 0]

@glennsarti
Copy link
Contributor

@joshcooper @mcdonaldseanp The encoder will also completely mangle the string if there are any double (or more) byte characters in there e.g. non english names or localised windows paths

irb(main):016:0> cmd = "\u07FF"
=> "\u07FF"
irb(main):017:0> puts cmd
߿
=> nil
irb(main):018:0>
irb(main):019:0> cmd = cmd.chars.to_a.join("\x00").chomp
=> "\u07FF"
irb(main):020:0> cmd << "\x00" unless cmd[-1].eql? "\x00"
=> "\u07FF\u0000"
irb(main):021:0> puts cmd.bytes
223
191
0
=> nil
irb(main):022:0>
irb(main):023:0> ("\u07FF".encode(Encoding::UTF_16LE)).bytes
=> [255, 7]
irb(main):024:0>

Previously the algorithm for encoding a command string to UTF-16LE would break down with byte chars in the string. This commit updates the helper to use the algorithm provided in the Encoding module.
@donoghuc donoghuc requested a review from a team as a code owner April 30, 2020 17:19
@donoghuc
Copy link
Contributor Author

I'm not sure the correct place to try to add the extra path escaping. here is what I tried first puppetlabs/beaker-puppet#135

@highb
Copy link
Contributor

highb commented May 15, 2020

I'm 👍 on getting this in the next beaker release since it'll remove the strange encoding logic that we're currently using.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

7 participants