`init_auth': undefined method` split' for nil:NilClass #208

JaBurd · 2016-05-03T18:28:47Z

When running a kitchen converge on a windows node from my Mac I'm getting the following error when Kitchen attempts to connect via winrm to my ec2 instance. Please note I have proxies involved and are most likely the culprit, but would like to see if its not something I'm doing wrong.

>>>>>> ------Exception-------
>>>>>> Class: Kitchen::ActionFailed
>>>>>> Message: Failed to complete #converge action: [undefined method `split' for nil:NilClass]
>>>>>> ----------------------
>>>>>> Please see .kitchen/logs/kitchen.log for more details
>>>>>> Also try running `kitchen diagnose --all` for configuration

Doing some additional digging I attempted to isolate the winrm connection and using the readme I built a ruby script to perform the winrm connection independently:

require 'winrm'
endpoint = 'http://ipaddress:5985/wsman'
winrm = WinRM::WinRMWebService.new(endpoint, :negotiate, :user => 'Administrator', :pass => 'password')
winrm.create_executor do |executor|
    executor.run_cmd('ipconfig /all') do |stdout, stderr|
        STDOUT.print stdout
        STDERR.print stderr
    end
end

This returns the following error:

.chefdk/gem/ruby/2.1.0/gems/winrm-1.8.0/lib/winrm/http/transport.rb:231:in `init_auth': undefined method `split' for nil:NilClass (NoMethodError)
from ~.chefdk/gem/ruby/2.1.0/gems/winrm-1.8.0/lib/winrm/http/transport.rb:171:in `send_request'
from ~.chefdk/gem/ruby/2.1.0/gems/winrm-1.8.0/lib/winrm/winrm_service.rb:492:in `send_message'
from ~.chefdk/gem/ruby/2.1.0/gems/winrm-1.8.0/lib/winrm/winrm_service.rb:393:in `run_wql'
from ~.chefdk/gem/ruby/2.1.0/gems/winrm-1.8.0/lib/winrm/command_executor.rb:190:in `os_version'
from ~.chefdk/gem/ruby/2.1.0/gems/winrm-1.8.0/lib/winrm/command_executor.rb:149:in `code_page'
from ~.chefdk/gem/ruby/2.1.0/gems/winrm-1.8.0/lib/winrm/command_executor.rb:72:in `block in open'
from ~.chefdk/gem/ruby/2.1.0/gems/winrm-1.8.0/lib/winrm/command_executor.rb:222:in `retryable'
from ~.chefdk/gem/ruby/2.1.0/gems/winrm-1.8.0/lib/winrm/command_executor.rb:71:in `open'
from ~.chefdk/gem/ruby/2.1.0/gems/winrm-1.8.0/lib/winrm/winrm_service.rb:359:in `create_executor'
from winrm_test.rb:4:in `<main>'`

Reviewing the code, it appears this is the negotiate step, but I don't have enough knowledge of winrm to know what exactly is failing and it must be nil because r isn't getting populated.

def init_auth
  @logger.debug "Initializing Negotiate for #{@service}"
  auth1 = @ntlmcli.init_context
  hdr = {"Authorization" => "Negotiate #{auth1.encode64}",
         "Content-Type" => "application/soap+xml;charset=UTF-8"
  }
  @logger.debug "Sending HTTP POST for Negotiate Authentication"
  r = @httpcli.post(@endpoint, "", hdr)
  verify_ssl_fingerprint(r.peer_cert)
  itok = r.header["WWW-Authenticate"].pop.split.last
  binding = r.peer_cert.nil? ? nil : Net::NTLM::ChannelBinding.create(r.peer_cert)
  auth3 = @ntlmcli.init_context(itok, binding)
  { "Authorization" => "Negotiate #{auth3.encode64}" }
end

Any thoughts, ideas appreciated.

The text was updated successfully, but these errors were encountered:

mwrock · 2016-05-03T18:41:34Z

Yup. definitely a proxy issue. This reminds me that we REALLY need a proxy section in the readme and better error messages here that say something like "maybe you are using a proxy so try this..." So even if the below unblocks tou, lets keep this open so its not forgotten.

The guidance of "This" would be to set the HTTP_PROXY and HTTPS_PROXY environment variables to point to your proxy endpoint in the form of http://proxy.server:proxyPort

JaBurd · 2016-05-03T18:50:56Z

I equally agree that this is most likely a proxy issue. I get that error when my ENV proxies are set as suggested.

When I go off proxy (remove the env variables) I get an expected Connection Refused error.

WARN  WinRM::WinRMWebService : [WinRM] connection failed, terminating (#<Errno::ECONNREFUSED: Connection refused - connect(2) for "ipaddress" port 5985 (ipaddress:5985)>)
~.chefdk/gem/ruby/2.1.0/gems/httpclient-2.8.0/lib/httpclient/session.rb:597:in `initialize': Connection refused - connect(2) for "ipaddress" port 5985 (ipaddress:5985) (Errno::ECONNREFUSED)

Could my proxies be setup to mess with or interrupt my winrm traffic specifically? Are there any other tests I could run to help identify the issue I'm seeing?

mwrock · 2016-05-03T19:02:30Z

Hmm. Its possible that winrm simply is not listnening, the firewall is blocking it or you don't have port mappings setup propperly in EC2. First thing i do is RDP (ugh...i know) to the EC2 instance and running:

Enable-PSRemoting -Force
Get-NetFirewallPortFilter | ?{$_.LocalPort -eq 5985 } | Get-NetFirewallRule | ?{ _.Direction –eq "Inbound" -and  $_.Profile -eq "Public" -and $_.Action –eq "Allow"} | Set-NetFirewallRule -RemoteAddress "Any"

This will ensure winrm is "on" and the 5985 firewall rule is wide open and not just the local subnet.

JaBurd · 2016-05-03T19:08:46Z

Been there, done that as well, I will double check those though, it cannot hurt. I do also sometimes get these.

WARN  WinRM::WinRMWebService : [WinRM] connection failed, terminating (#<WinRM::WinRMHTTPTransportError: Bad HTTP response returned from server (302).>)
~.chefdk/gem/ruby/2.1.0/gems/winrm-1.8.0/lib/winrm/http/response_handler.rb:79:in `raise_transport_error': Bad HTTP response returned from server (302). (WinRM::WinRMHTTPTransportError)

I'm going to go with our proxies are causing some disconnect. We recently had to change proxy addresses and perhaps something is blocked on the new proxies that was open on the old proxies.

JaBurd · 2016-05-03T19:58:19Z

The above was a result of turning SSL on which I don't think our servers are setup for.

JaBurd · 2016-05-05T13:47:37Z

I composed an email to our proxy team, but haven't heard anything back. As a workaround, I'm fortunate to have a linux jump host that I was able to establish a local SSH tunnel for port 5985. Modified my default-windows-2012r2.yml to point to 127.0.0.1 and I'm able to converge properly after the initial failure.

Thank you @mwrock for your time and attention.

dougireton · 2016-06-04T03:49:55Z

I have a related issue. It appears that the winrm gem doesn't honor the no_proxy env var. The WSMan connection to 5985 is going through our Proxy Server which blocks the connection.

Only Internet-bound traffic should go through our Web Proxies. Traffic to our AWS VPC should not go through our proxy.

Background

We have no_proxy set to 172.16.0.0/12

Steps to Reproduce:

kitchen converge windows with this .kitchen.yml:

# <snip>

driver:
  name: ec2
  http_proxy: http://proxygateway1.nordstrom.net:8181
  https_proxy: http://proxygateway1.nordstrom.net:8181
  no_proxy: nordstrom.net,localhost,127.0.0.1,169.254.169.254,172.16.0.0/12
  aws_ssh_key_id: <%= aws_ssh_key_id %>
  region: us-west-2
  instance_type: t2.small
  subnet_id: <%= subnet_foo_az1 %>
  security_group_ids: <%= security_group_ids %>

transport:
  ssh_key: <%= aws_ssh_key %>

platforms:
  - name: windows-2012r2
    image_search:
      architecture: x86_64
      name: Windows_Server-2012-R2_RTM-English-64Bit-Base-2016.*

HTTP response from our Proxy server:

URL: POST http://172.20.26.181/wsman<br />\nCategory: Uncategorized URLs<br />\nReason: UNKNOWN<br />\nNotification: GATEWAY_TIMEOUT\n</p></div>\n</body>\n</html>\n",

@header_item=
 [["Mime-Version", "1.0"],
  ["Date", "Fri, 03 Jun 2016 23:15:19 GMT"],
  ["Via", "1.1 proxygateway1.nordstrom.net:80 (Cisco-WSA/8.5.3-069)"],
  ["Content-Type", "text/html"],
  ["Connection", "keep-alive"],
  ["Proxy-Connection", "keep-alive"],
  ["Content-Length", "2703"]],
@http_version="1.1",
@is_request=false,
@reason_phrase="Gateway Timeout",
@request_absolute_uri=nil,
@request_method="POST",
@request_query=nil,
@request_uri=#<URI::HTTP:0x007fe48ad8ebd8 URL:http://172.20.26.181:5985/wsman>,

Stacktrace:

D      ------Exception-------
D      Class: Kitchen::ActionFailed
D      Message: Failed to complete #create action: [undefined method `split' for nil:NilClass]
D      ---Nested Exception---
D      Class: NoMethodError
D      Message: undefined method `split' for nil:NilClass
D      ------Backtrace-------
D      /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/http/transport.rb:226:in `init_auth'
D      /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/http/transport.rb:166:in `send_request'
D      /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/winrm_service.rb:489:in `send_message'
D      /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/winrm_service.rb:390:in `run_wql'
D      /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/command_executor.rb:186:in `os_version'
D      /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/command_executor.rb:145:in `code_page'
D      /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/command_executor.rb:72:in `block in open'
D      /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/command_executor.rb:218:in `retryable'
D      /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/command_executor.rb:71:in `open'
D      /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/winrm_service.rb:356:in `create_executor'
D      /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/test-kitchen-1.7.3/lib/kitchen/transport/winrm.rb:321:in `session'
D      /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/test-kitchen-1.7.3/lib/kitchen/transport/winrm.rb:135:in `wait_until_ready'
D      /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/kitchen-ec2-1.0.0/lib/kitchen/driver/ec2.rb:205:in `create'
D      /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/test-kitchen-1.7.3/lib/kitchen/instance.rb:449:in `public_send'
D      /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/test-kitchen-1.7.3/lib/kitchen/instance.rb:449:in `block in perform_action'

mwrock · 2016-06-06T12:49:44Z

Hey @dougireton try setting ENV['no_proxy'] prior to calling kitchen and see if that works around the issue. winrm uses the httpclient gem for all of its http glue which should honor the *_proxy variables. I'm betting the EC2 kitchen driver just doesn't set this in the environment.

dougireton · 2016-06-09T01:06:38Z

@mwrock Here's my no_proxy setting. I assume httpclient will honor CIDR notation for subnets?

no_proxy=localhost,127.0.0.1,172.16.0.0/12

mwrock · 2016-06-09T01:33:35Z

Hmm. doesn't look like cidr is valid: https://github.com/nahi/httpclient/blob/master/lib/httpclient.rb#L521-530

  # Sets NO_PROXY setting String.  no_proxy must be a comma separated String.
  # Each entry must be 'host' or 'host:port' such as;
  # HTTPClient#no_proxy = 'example.com,example.co.jp:443'

dougireton · 2016-06-09T14:17:05Z

@mwrock the issue is that when WinRM tries to connect to the wsman endpoint it uses the IP address and not a DNS address so we'd have to know the guest IP ahead of time and add it to no_proxy which isn't realistic. :(

Here's an example of the endpoint address it tries to connect to:
URL:http://172.20.2.5:5985/wsman

oifland · 2016-06-10T22:26:00Z

Just to add to this, I'm in the same situation and I added the full IP address to my no_proxy (after running kitchen create) and then kitchen converge worked. So theoretically, CIDR support should fix this issue.

cheeseplus · 2016-06-14T18:39:16Z

The issue with supporting CIDR in test-kitchen is that no_proxy is an OS level thing with how it uses the ENV var. We can't really support CIDR because the underlying mechanism doesn't.

oifland · 2016-06-14T18:42:24Z

Yeah, I was just looking at the underlying code. It would be ideal to fix this issue at that level. I looked around at some similar implementations in other libraries and it looks like go and chrome both have libraries that support CIDR blocks, so there's some (external) precedence for supporting CIDR blocks.

mwrock · 2016-06-14T18:46:19Z

The httpclient gem owns the underlying code: https://github.com/nahi/httpclient/blob/master/lib/httpclient.rb and is the best place to add cidr support

oifland · 2016-06-14T18:48:38Z

Yes, I may attempt a PR for it later this week. https://github.com/nahi/httpclient/blob/master/lib/httpclient.rb#L521-530

jeremymv2 · 2016-06-15T12:45:28Z

Let's set no_proxy CIDR aside for a bit and focus on the reported problem which seemingly is a proxy usage issue with winrm.

There is another customer who is reporting the same problem with very similar stack trace:

       EC2 instance <i-91a63a0d> ready.
D      ------Exception-------
D      Class: Kitchen::ActionFailed
D      Message: Failed to complete #create action: [undefined method `split' for nil:NilClass]
D      ---Nested Exception---
D      Class: NoMethodError
D      Message: undefined method `split' for nil:NilClass
D      ------Backtrace-------
D      C:/opscode/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/http/transport.rb:226:in `init_auth'
D      C:/opscode/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/http/transport.rb:166:in `send_request'
D      C:/opscode/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/winrm_service.rb:489:in `send_message'
D      C:/opscode/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/winrm_service.rb:390:in `run_wql'
D      C:/opscode/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/command_executor.rb:186:in `os_version'
D      C:/opscode/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/command_executor.rb:145:in `code_page'
D      C:/opscode/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/command_executor.rb:72:in `block in open'
D      C:/opscode/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/command_executor.rb:218:in `retryable'
D      C:/opscode/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/command_executor.rb:71:in `open'
D      C:/opscode/chefdk/embedded/lib/ruby/gems/2.1.0/gems/winrm-1.7.3/lib/winrm/winrm_service.rb:356:in `create_executor'

Winrm works fine with ChefDK 0.10.0 for them. When they try either 0.13.21 or 0.14.25 they get the above error / stack trace.

mwrock · 2016-06-16T01:37:05Z

@jeremymv2 we definitely need better error messaging here but I'd be curious if setting the HTTP_PROXY and HTTPS_PROXY environment variables would help the customer get past the error.

rayterrill · 2016-06-29T05:33:59Z

I'm hitting the same issue when running kitchen converge or vagrant up from Windows7 on VMWare Workstation with proxy settings set via $env:http_proxy and $env:https_proxy.

If I launch a new PS session without the proxy settings, and run vagrant up, vagrant fails to check if the box is the latest version (can't get out without proxy settings), but succeeds in building the VM.

…#208

uvsmtid · 2016-07-21T02:59:01Z

Just one more case to the list...

I'm using Vagrant with libvirt provider on Linux host machine to run guest Windows 2012 R2 and hitting the same issue. The host machine network is behind a proxy - so, it is normal thathttp_proxy and https_proxy environment variables are set in shell by default to access Internet.

This command fails:

vagrant up --provider libvirt
...
/opt/vagrant/embedded/gems/gems/winrm-1.8.1/lib/winrm/http/transport.rb:228:in `init_auth': undefined method `split' for nil:NilClass (NoMethodError)

Unsetting environment variables (parentheses to unset temporary for vagrant only) avoids the problem.
This command succeeds:

(unset http_proxy https_proxy ; vagrant up --provider libvirt)

The proxy variables are definitely set correctly because downloads from Internet via wget (command which also respects these environment variables) work perfectly.

Focus

I want to put this focus on the issue:
What I don't get is why HTTP(S) proxy settings are used in non-HTTP(S) protocol communication? Correct me if I'm wrong, but there seems to be absolutely nothing in winrm to rely on HTTP(S) to actually pick up the proxy settings from the http(s)_proxy environment variable(s).

Note also that I'm not connecting to guest VM over any real network - all communication is local over virtual interfaces (as compared to some cases mentioning AWS above). So, again, since reliance on Internet is ruled out (where HTTP is predominant), there should not be no reason to fail.

majkinetor · 2016-10-26T08:32:08Z

I just experienced this issue. There is a library I use for this in Powershell now: https://github.com/majkinetor/posh/blob/master/MM_Network/Update-CLIProxy.ps1

I use with number of tools such as git, pip etc... to set up console proxy, but here it is used to reset it:

PS> proxyc -FromSystem
$Env:ftp_proxy   = 'http://10.35.9.55:8080'
$Env:http_proxy  = 'http://10.35.9.55:8080'
$Env:https_proxy = 'http://10.35.9.55:8080'
$Env:no_proxy    = '10.*,<local>

proxyc -Clear; vagrant up

mwrock · 2016-10-27T05:45:03Z

For clarification, WinRM is indeed an HTTP/HTTPS transport. It relays commands to and from a remote machine via a SOAP service on the remote node. The winrm gem uses the http-client gem to manage this communication which will honor the HTTP_PROXY, HTTPS_PROXY and NO_PROXY variables.

sonic0002 · 2017-03-08T15:30:47Z

Sometimes it would be simply a problem that the port 5985 is being used by other applications instead of WinRM service. See Ruby WinRM undefined method `split' for nil:NilClass

mwrock added a commit that referenced this issue Jul 7, 2016

raise a better error if the auth headers cant be parsed as reported in …

dffce9c

…#208

sneal mentioned this issue Jul 7, 2016

WinRM V2 #191

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

`init_auth': undefined method` split' for nil:NilClass #208

`init_auth': undefined method` split' for nil:NilClass #208

JaBurd commented May 3, 2016

mwrock commented May 3, 2016

JaBurd commented May 3, 2016

mwrock commented May 3, 2016

JaBurd commented May 3, 2016

JaBurd commented May 3, 2016

JaBurd commented May 5, 2016

dougireton commented Jun 4, 2016 •

edited

Loading

mwrock commented Jun 6, 2016

dougireton commented Jun 9, 2016

mwrock commented Jun 9, 2016

dougireton commented Jun 9, 2016

oifland commented Jun 10, 2016

cheeseplus commented Jun 14, 2016

oifland commented Jun 14, 2016

mwrock commented Jun 14, 2016

oifland commented Jun 14, 2016

jeremymv2 commented Jun 15, 2016 •

edited

Loading

mwrock commented Jun 16, 2016

rayterrill commented Jun 29, 2016

uvsmtid commented Jul 21, 2016 •

edited

Loading

majkinetor commented Oct 26, 2016

mwrock commented Oct 27, 2016

sonic0002 commented Mar 8, 2017

init_auth': undefined method split' for nil:NilClass #208

init_auth': undefined method split' for nil:NilClass #208

Comments

JaBurd commented May 3, 2016

mwrock commented May 3, 2016

JaBurd commented May 3, 2016

mwrock commented May 3, 2016

JaBurd commented May 3, 2016

JaBurd commented May 3, 2016

JaBurd commented May 5, 2016

dougireton commented Jun 4, 2016 • edited Loading

Background

Steps to Reproduce:

HTTP response from our Proxy server:

Stacktrace:

mwrock commented Jun 6, 2016

dougireton commented Jun 9, 2016

mwrock commented Jun 9, 2016

dougireton commented Jun 9, 2016

oifland commented Jun 10, 2016

cheeseplus commented Jun 14, 2016

oifland commented Jun 14, 2016

mwrock commented Jun 14, 2016

oifland commented Jun 14, 2016

jeremymv2 commented Jun 15, 2016 • edited Loading

mwrock commented Jun 16, 2016

rayterrill commented Jun 29, 2016

uvsmtid commented Jul 21, 2016 • edited Loading

Focus

majkinetor commented Oct 26, 2016

mwrock commented Oct 27, 2016

sonic0002 commented Mar 8, 2017

`init_auth': undefined method` split' for nil:NilClass #208

`init_auth': undefined method` split' for nil:NilClass #208

dougireton commented Jun 4, 2016 •

edited

Loading

jeremymv2 commented Jun 15, 2016 •

edited

Loading

uvsmtid commented Jul 21, 2016 •

edited

Loading