search

audiolize / vagrant-softlayer

This is a Vagrant plugin that adds a SoftLayer provider to Vagrant, allowing Vagrant to control and provision SoftLayer CCI instances.
MIT License
42 stars 15 forks source link

SoftLayer API Errors and warden.rb #46

Closed sercanaktas closed 9 years ago

sercanaktas commented 9 years ago

Hello,

I've been encountering the following errors quite frequently since last week. It looks like it's occurring in warden.rb. I've attached a stack trace with debug flag on.

The stack trace is the same though the exception is different.

>Exception class: EOFError
>Exception message: end of file reached

>Exception class: RuntimeError
>Exception message: Wrong type NilClass. Not allowed!

>Exception class: RuntimeError
>Exception message: Wrong size. Was 1460, should be 2999

>Exception class: RuntimeError
>Exception message: Wrong size. Was 1460, should be 3321

>Exception class: Net::ReadTimeout
>Exception message: Net::ReadTimeout

Sample stack trace below:

==> base01: Creating a new SoftLayer instance...
ERROR warden: Error occurred: Vagrant returned an exception while calling the SoftLayer API.

Exception class: VagrantPlugins::SoftLayer::Errors::SLApiError
Exception message: Vagrant returned an exception while calling the SoftLayer API.

Exception class: Net::ReadTimeout
Exception message: Net::ReadTimeout
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
ERROR warden: Error occurred: Vagrant returned an exception while calling the SoftLayer API.

Exception class: VagrantPlugins::SoftLayer::Errors::SLApiError
Exception message: Vagrant returned an exception while calling the SoftLayer API.

Exception class: Net::ReadTimeout
Exception message: Net::ReadTimeout
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
ERROR warden: Error occurred: Vagrant returned an exception while calling the SoftLayer API.

Exception class: VagrantPlugins::SoftLayer::Errors::SLApiError
Exception message: Vagrant returned an exception while calling the SoftLayer API.

Exception class: Net::ReadTimeout
Exception message: Net::ReadTimeout
 INFO warden: Beginning recovery process...
 INFO warden: Calling recover: #<Vagrant::Action::Builtin::Call:0x3b43690>
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO environment: Released process lock: machine-action-dcd514a20cb632f4f705d734b71395b9
 INFO environment: Running hook: environment_unload
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 1 hooks defined.
 INFO runner: Running action: #<Vagrant::Action::Builder:0x244dca0>
ERROR vagrant: Vagrant experienced an error! Details:
ERROR vagrant: #<VagrantPlugins::SoftLayer::Errors::SLApiError: Vagrant returned an exception while calling the SoftLayer API.

Exception class: VagrantPlugins::SoftLayer::Errors::SLApiError
Exception message: Vagrant returned an exception while calling the SoftLayer API.

Exception class: Net::ReadTimeout
Exception message: Net::ReadTimeout>
ERROR vagrant: Vagrant returned an exception while calling the SoftLayer API.

Exception class: VagrantPlugins::SoftLayer::Errors::SLApiError
Exception message: Vagrant returned an exception while calling the SoftLayer API.

Exception class: Net::ReadTimeout
Exception message: Net::ReadTimeout
ERROR vagrant: C:/Users/sercan.aktas/.vagrant.d/gems/gems/vagrant-softlayer-0.4.0/lib/vagrant-softlayer/util/warden.rb:31:in `rescue in sl_warden'
C:/Users/sercan.aktas/.vagrant.d/gems/gems/vagrant-softlayer-0.4.0/lib/vagrant-softlayer/util/warden.rb:17:in `sl_warden'
C:/Users/sercan.aktas/.vagrant.d/gems/gems/vagrant-softlayer-0.4.0/lib/vagrant-softlayer/action/create_instance.rb:18:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/warden.rb:34:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/builtin/synced_folders.rb:84:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/warden.rb:34:in `call'
C:/Users/sercan.aktas/.vagrant.d/gems/gems/vagrant-hostmanager-1.5.0/lib/vagrant-hostmanager/action/update_all.rb:33:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/warden.rb:34:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/builtin/config_validate.rb:25:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/warden.rb:34:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/builtin/provision.rb:80:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/warden.rb:34:in `call'
C:/Users/sercan.aktas/.vagrant.d/gems/gems/vagrant-softlayer-0.4.0/lib/vagrant-softlayer/action/setup_softlayer.rb:34:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/warden.rb:34:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/warden.rb:95:in `block in finalize_action'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/warden.rb:34:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/warden.rb:34:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/builder.rb:116:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/runner.rb:66:in `block in run'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/util/busy.rb:19:in `busy'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/runner.rb:66:in `run'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/builtin/call.rb:53:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/warden.rb:34:in `call'
C:/Users/sercan.aktas/.vagrant.d/gems/gems/vagrant-softlayer-0.4.0/lib/vagrant-softlayer/action/setup_softlayer.rb:34:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/warden.rb:34:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/builtin/config_validate.rb:25:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/warden.rb:34:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/builtin/handle_box.rb:56:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/warden.rb:34:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/builder.rb:116:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/runner.rb:66:in `block in run'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/util/busy.rb:19:in `busy'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/action/runner.rb:66:in `run'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/machine.rb:196:in `action_raw'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/machine.rb:173:in `block in action'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/environment.rb:474:in `lock'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/machine.rb:161:in `call'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/machine.rb:161:in `action'
C:/HashiCorp/Vagrant/embedded/gems/gems/vagrant-1.6.5/lib/vagrant/batch_action.rb:82:in `block (2 levels) in run'
 INFO interface: error: Vagrant returned an exception while calling the SoftLayer API.

Exception class: VagrantPlugins::SoftLayer::Errors::SLApiError
Exception message: Vagrant returned an exception while calling the SoftLayer API.

Exception class: Net::ReadTimeout
Exception message: Net::ReadTimeout
Vagrant returned an exception while calling the SoftLayer API.

Exception class: VagrantPlugins::SoftLayer::Errors::SLApiError
Exception message: Vagrant returned an exception while calling the SoftLayer API.

Exception class: Net::ReadTimeout
Exception message: Net::ReadTimeout
 INFO interface: Machine: error-exit ["VagrantPlugins::SoftLayer::Errors::SLApiError", "Vagrant returned an exception while calling the SoftLayer API.\n\nException class: VagrantPlugins::SoftLayer::Errors::SLApiError\nException message: Vagrant returned an exception while calling the SoftLayer API.\
n\nException class: Net::ReadTimeout\nException message: Net::ReadTimeout"]
ju2wheels commented 9 years ago

What value do you currently have set for sl.api_timeout?

sercanaktas commented 9 years ago

It is not set, so I assume it is using the default 60 secs.

ju2wheels commented 9 years ago

Try increasing that but given the Runtime exceptions above it looks like it may occasionally be loosing packets as well so it might be a general network issue.

sercanaktas commented 9 years ago

Hi again,

I increased the sl.api_timeout to 500 secs and I am still getting the same errors. Though a new one is added;

Exception class: #Class:0x4277eb0 Exception message: execution expired

ju2wheels commented 9 years ago

Is this a windows box? Seems similar to this upstream issue, see if increasing the winrm timeout helps if you are building a windows box. If not theres also the sl.provision_timeout you can try setting.

sercanaktas commented 9 years ago

It is CentOS

ju2wheels commented 9 years ago 
$ ./vagrant-softlayer-credentials software list -y
ERROR: Failed to perform action list on credential category software: execution expired

I started hitting this myself this morning and have never actually seen it before it, happened when my internet went down due to the snowstorm in the North East so it probably is just a general network issue.

sercanaktas commented 9 years ago

I would like to place some 'puts' commands to see which API calls are made by vagrant-softlayer and what are their responses. Any suggestions where in which file I should do that?

ju2wheels commented 9 years ago

Theres a few calls it puts in depending on what options you select but the general:

  1. Check if machine id exists if already created
  2. Verify order selection and place order
  3. Wait for server provision to finish
  4. Get IP Address
  5. Wait for IP to become reachable on ssh (internal vagrant code).
  6. sync folders over ssh

There may also be the joining of the load balancer if you have that configured. But the above would be the important points where it interfaces with softlayer_api and the API itself.

sercanaktas commented 9 years ago

Thanks I will look into it more and keep this updated

sercanaktas commented 9 years ago

More information for you;

When I run vagrant from a linux machine, it runs without a problem. Sadly our development machines are Windows and we are using Windows Command Prompt since Cygwin has problems with softlayer. And in Windows machine I get these problems. Do you have any insight on this?

ju2wheels commented 9 years ago

Cygwin has problems with softlayer

I havent used SL or vagrant-softlayer on Windows at all so Im not sure what you are hitting here. Other than a possible difficultly in ensuring you have all the right dependencies installed or possible issues with Cygwin -> Windows path transformations I dont see why it wouldnt work.

With the info provided above all I can tell is it looks like a general network issue, but if you want to provide further details we can reopen and try to continue troubleshoot.