Chef recipe for python causing "vagrant up" to fail

[ryanjarvis]

When attempting to run "vagrant up" and having the virtual machine build, the python recipe fails when attempting to install pip.

Chef::Exceptions::EnclosingDirectoryDoesNotExist: remote_file[/var/chef/cache/distribute_setup.py] (python::pip line 33) had an error: Chef::Exceptions::EnclosingDirectoryDoesNotExist: Parent direcory /var/chef/cache does not exist.

[teleyinex]

@ryanjarvis You are right! The requirement swig is not installed and that's why is failing. I'm fixing it right now! I'll keep you posted.

Thanks a lot for reporting the issue!

[teleyinex]

Can you try again after pulling the changes? Please, let me know if it is fixed or not. After this fix, I've tried again and it worked.

[ryanjarvis]

Thanks for the quick response, but no this hasn't fixed my problem yet.

The above error is being thrown at line 33 of /cookbooks/python/recipes/pip.rb This is the python recipe not the pybossa recipe, which, as far as I can understand, gets processed first.

Is there a full log or stacktrace I could give you somehow?

[teleyinex]

Hi,

Sorry to hear that it is not fixed. The pip recipe as you have said it is a different one and I'm using the defaults, so maybe there is something broken there, however why did it worked for me?

You should get a full error in the terminal, can you copy and paste the error here? It will be also good if you can open an issue in the pip cookbook so the authors can review it.

Cheers,

Daniel

[ryanjarvis]

Here is the exact output I get when I clone the pybossa repo and call vagrant up:

Bringing machine 'default' up with 'virtualbox' provider...
[default] Importing base box 'precise32'...

[default] Matching MAC address for NAT networking...
[default] Setting the name of the VM...
[default] Clearing any previously set forwarded ports...
[default] Fixed port collision for 22 => 2222. Now on port 2200.
[default] Fixed port collision for 5000 => 5000. Now on port 2201.
[default] Creating shared folders metadata...
[default] Clearing any previously set network interfaces...
[default] Preparing network interfaces based on configuration...
[default] Forwarding ports...
[default] -- 22 => 2200 (adapter 1)
[default] -- 5000 => 2201 (adapter 1)
[default] Booting VM...
[default] Waiting for VM to boot. This can take a few minutes.
[default] VM booted and ready for use!
[default] Mounting shared folders...
[default] -- /vagrant
[default] -- /tmp/vagrant-chef-1/chef-solo-1/cookbooks
[default] Running provisioner: chef_solo...
Generating chef JSON and uploading...
Running chef-solo...
�[31mstdin: is not a tty�[0m
�[32m[2013-07-23T15:49:30+00:00] INFO: *** Chef 10.14.2 ***�[0m
�[32m[2013-07-23T15:49:30+00:00] INFO: Setting the run_list to ["recipe[apt]", "recipe[postgresql]", "recipe[git]", "recipe[python]", "recipe[pybossa]"] from JSON�[0m
�[32m[2013-07-23T15:49:30+00:00] INFO: Run List is [recipe[apt], recipe[postgresql], recipe[git], recipe[python], recipe[pybossa]]�[0m
�[32m[2013-07-23T15:49:30+00:00] INFO: Run List expands to [apt, postgresql, git, python, pybossa]�[0m
�[32m[2013-07-23T15:49:30+00:00] INFO: Starting Chef Run for precise32�[0m
�[32m[2013-07-23T15:49:30+00:00] INFO: Running start handlers�[0m
�[32m[2013-07-23T15:49:30+00:00] INFO: Start handlers complete.�[0m
�[32m[2013-07-23T15:49:30+00:00] INFO: Processing execute[apt-get-update] action run (apt::default line 22)�[0m
�[32m[2013-07-23T15:49:33+00:00] INFO: execute[apt-get-update] ran successfully�[0m
�[32m[2013-07-23T15:49:33+00:00] INFO: Processing execute[apt-get update] action nothing (apt::default line 29)�[0m
�[32m[2013-07-23T15:49:33+00:00] INFO: Processing execute[apt-get autoremove] action nothing (apt::default line 36)�[0m
�[32m[2013-07-23T15:49:33+00:00] INFO: Processing execute[apt-get autoclean] action nothing (apt::default line 42)�[0m
�[32m[2013-07-23T15:49:33+00:00] INFO: Processing package[update-notifier-common] action install (apt::default line 48)�[0m
�[32m[2013-07-23T15:49:34+00:00] INFO: package[update-notifier-common] sending run action to execute[apt-get-update] (immediate)�[0m
�[32m[2013-07-23T15:49:34+00:00] INFO: Processing execute[apt-get-update] action run (apt::default line 22)�[0m
�[32m[2013-07-23T15:49:38+00:00] INFO: execute[apt-get-update] ran successfully�[0m
�[32m[2013-07-23T15:49:38+00:00] INFO: Processing execute[apt-get-update-periodic] action run (apt::default line 52)�[0m
�[32m[2013-07-23T15:49:38+00:00] INFO: Processing directory[/var/cache/local] action create (apt::default line 62)�[0m
�[32m[2013-07-23T15:49:38+00:00] INFO: directory[/var/cache/local] created directory /var/cache/local�[0m
�[32m[2013-07-23T15:49:38+00:00] INFO: directory[/var/cache/local] owner changed to 0�[0m
�[32m[2013-07-23T15:49:38+00:00] INFO: directory[/var/cache/local] group changed to 0�[0m
�[32m[2013-07-23T15:49:38+00:00] INFO: directory[/var/cache/local] mode changed to 755�[0m
�[32m[2013-07-23T15:49:38+00:00] INFO: Processing directory[/var/cache/local/preseeding] action create (apt::default line 62)�[0m
�[32m[2013-07-23T15:49:38+00:00] INFO: directory[/var/cache/local/preseeding] created directory /var/cache/local/preseeding�[0m
�[32m[2013-07-23T15:49:38+00:00] INFO: directory[/var/cache/local/preseeding] owner changed to 0�[0m
�[32m[2013-07-23T15:49:38+00:00] INFO: directory[/var/cache/local/preseeding] group changed to 0�[0m
�[32m[2013-07-23T15:49:38+00:00] INFO: directory[/var/cache/local/preseeding] mode changed to 755�[0m
�[32m[2013-07-23T15:49:38+00:00] INFO: Processing package[postgresql-client] action install (postgresql::client line 32)�[0m
�[32m[2013-07-23T15:49:40+00:00] INFO: Processing package[libpq-dev] action install (postgresql::client line 32)�[0m
�[32m[2013-07-23T15:49:42+00:00] INFO: Processing package[git] action install (git::default line 24)�[0m
�[32m[2013-07-23T15:49:46+00:00] INFO: Processing package[python] action install (python::package line 40)�[0m
�[32m[2013-07-23T15:49:46+00:00] INFO: Processing package[python-dev] action install (python::package line 40)�[0m
�[32m[2013-07-23T15:49:57+00:00] INFO: Processing remote_file[/var/chef/cache/distribute_setup.py] action create (python::pip line 33)�[0m
�[32m�[0m
�[32m================================================================================�[0m
�[32m�[0m
�[32mError executing action `create` on resource 'remote_file[/var/chef/cache/distribute_setup.py]'�[0m
�[32m�[0m
�[32m================================================================================�[0m
�[32m�[0m
�[32m�[0m
�[32mChef::Exceptions::EnclosingDirectoryDoesNotExist�[0m
�[32m�[0m
�[32m------------------------------------------------�[0m
�[32m�[0m
�[32mParent directory /var/chef/cache does not exist.�[0m
�[32m�[0m
�[32m�[0m
�[32mResource Declaration:�[0m
�[32m�[0m
�[32m---------------------�[0m
�[32m�[0m
�[32m# In /tmp/vagrant-chef-1/chef-solo-1/cookbooks/python/recipes/pip.rb

 32: # https://bitbucket.org/ianb/pip/issue/104/pip-uninstall-on-ubuntu-linux
 33: remote_file "#{Chef::Config[:file_cache_path]}/distribute_setup.py" do
 34:   source node['python']['distribute_script_url']
 35:   mode "0644"
 36:   not_if { ::File.exists?(pip_binary) }
 37: end
 38: �[0m
�[32m�[0m
�[32mCompiled Resource:�[0m
�[32m�[0m
�[32m------------------�[0m
�[32m�[0m
�[32m# Declared in /tmp/vagrant-chef-1/chef-solo-1/cookbooks/python/recipes/pip.rb:33:in `from_file'

remote_file("/var/chef/cache/distribute_setup.py") do
  mode "0644"
  retry_delay 2
  path "/var/chef/cache/distribute_setup.py"
  retries 0
  recipe_name "pip"
  source "http://python-distribute.org/distribute_setup.py"
  action "create"
  cookbook_name :python
  backup 5
  provider Chef::Provider::RemoteFile
  not_if { #code block }
end

[2013-07-23T15:49:57+00:00] ERROR: Running exception handlers
[2013-07-23T15:49:57+00:00] ERROR: Exception handlers complete�[0m
�[32m[2013-07-23T15:49:57+00:00] FATAL: Stacktrace dumped to /var/chef/cache/chef-stacktrace.out�[0m
�[32m[2013-07-23T15:49:57+00:00] FATAL: Chef::Exceptions::EnclosingDirectoryDoesNotExist: remote_file[/var/chef/cache/distribute_setup.py] (python::pip line 33) had an error: Chef::Exceptions::EnclosingDirectoryDoesNotExist: Parent directory /var/chef/cache does not exist.�[0m
�[31mChef never successfully completed! Any errors should be visible in the
output above. Please fix your recipes so that they properly complete.�[0m

[teleyinex]

Hi,

interestingly now I'm getting an error, not in pip, but when installing the requirements of Flask-Babel. According to the output error it cannot find the right version for pytz package, which is strange as it works outside the VM. I'm checking it.

Regarding your issue: it seems like this has happened before. Can you try to upgrade in your copy to the latest python cookbook and try again?

[teleyinex]

Hi again,

I found the problem. With the current set up, vagrant chef cookbook for python installs pip 1.4 which is incompatible with pytz. I'm looking for a fix :-)

[ryanjarvis]

What version of Vagrant are you using?

I am using 1.2.4. The fact that we are getting different errors suggest to me we aren't using the same tools. I downloaded the latest Opscode Python cookbook and I still get the same error.

I found this issue: https://groups.google.com/forum/#!topic/vagrant-up/vJbAT6iWlt8
Apparently the error I am having affects recipes for other things like Java, not just Python. And so far it looks like my error is for Vagrant 1.2.4

[teleyinex]

Hi,

Good point! I'm with version 1.2.2. Can you install version 1.2.2 to see if the version is the problem?

[ryanjarvis]

The plot thickens...

Below is my log showing a new error when I use Vagrant 1.2.2. Everything provisions except for Pybossa. Long story short: your first call to create a python virtual environment fails for me.

I went ahead and googled "virtualenv protocol error" and I found a couple links that might help you figure out what to do:
http://stackoverflow.com/a/15768760
hashicorp/vagrant#713

Bringing machine 'default' up with 'virtualbox' provider...
[default] Importing base box 'precise32'...
[default] Matching MAC address for NAT networking...
[default] Setting the name of the VM...
[default] Clearing any previously set forwarded ports...
[default] Creating shared folders metadata...
[default] Clearing any previously set network interfaces...
[default] Preparing network interfaces based on configuration...
[default] Forwarding ports...
[default] -- 22 => 2222 (adapter 1)
[default] -- 5000 => 5000 (adapter 1)
[default] Booting VM...
[default] Waiting for VM to boot. This can take a few minutes.
[default] VM booted and ready for use!
[default] Configuring and enabling network interfaces...
[default] Mounting shared folders...
[default] -- /vagrant
[default] -- /tmp/vagrant-chef-1/chef-solo-1/cookbooks
[default] Running provisioner: chef_solo...
Generating chef JSON and uploading...
Running chef-solo...
stdin: is not a tty
[2013-07-24T17:05:42+00:00] INFO: *** Chef 10.14.2 ***
[2013-07-24T17:05:42+00:00] INFO: Setting the run_list to ["recipe[apt]", "recipe[postgresql]", "recipe[git]", "recipe[python]", "recipe[pybossa]"] from JSON
[2013-07-24T17:05:42+00:00] INFO: Run List is [recipe[apt], recipe[postgresql], recipe[git], recipe[python], recipe[pybossa]]
[2013-07-24T17:05:42+00:00] INFO: Run List expands to [apt, postgresql, git, python, pybossa]
[2013-07-24T17:05:42+00:00] INFO: Starting Chef Run for precise32
[2013-07-24T17:05:42+00:00] INFO: Running start handlers
[2013-07-24T17:05:42+00:00] INFO: Start handlers complete.
[2013-07-24T17:05:42+00:00] INFO: Processing execute[apt-get-update] action run (apt::default line 22)
[2013-07-24T17:05:46+00:00] INFO: execute[apt-get-update] ran successfully
[2013-07-24T17:05:46+00:00] INFO: Processing execute[apt-get update] action nothing (apt::default line 29)
[2013-07-24T17:05:46+00:00] INFO: Processing execute[apt-get autoremove] action nothing (apt::default line 36)
[2013-07-24T17:05:46+00:00] INFO: Processing execute[apt-get autoclean] action nothing (apt::default line 42)
[2013-07-24T17:05:46+00:00] INFO: Processing package[update-notifier-common] action install (apt::default line 48)
[2013-07-24T17:05:47+00:00] INFO: package[update-notifier-common] sending run action to execute[apt-get-update] (immediate)
[2013-07-24T17:05:47+00:00] INFO: Processing execute[apt-get-update] action run (apt::default line 22)
[2013-07-24T17:05:49+00:00] INFO: execute[apt-get-update] ran successfully
[2013-07-24T17:05:49+00:00] INFO: Processing execute[apt-get-update-periodic] action run (apt::default line 52)
[2013-07-24T17:05:49+00:00] INFO: Processing directory[/var/cache/local] action create (apt::default line 62)
[2013-07-24T17:05:49+00:00] INFO: directory[/var/cache/local] created directory /var/cache/local
[2013-07-24T17:05:49+00:00] INFO: directory[/var/cache/local] owner changed to 0
[2013-07-24T17:05:49+00:00] INFO: directory[/var/cache/local] group changed to 0
[2013-07-24T17:05:49+00:00] INFO: directory[/var/cache/local] mode changed to 755
[2013-07-24T17:05:49+00:00] INFO: Processing directory[/var/cache/local/preseeding] action create (apt::default line 62)
[2013-07-24T17:05:49+00:00] INFO: directory[/var/cache/local/preseeding] created directory /var/cache/local/preseeding
[2013-07-24T17:05:49+00:00] INFO: directory[/var/cache/local/preseeding] owner changed to 0
[2013-07-24T17:05:49+00:00] INFO: directory[/var/cache/local/preseeding] group changed to 0
[2013-07-24T17:05:49+00:00] INFO: directory[/var/cache/local/preseeding] mode changed to 755
[2013-07-24T17:05:49+00:00] INFO: Processing package[postgresql-client] action install (postgresql::client line 32)
[2013-07-24T17:05:50+00:00] INFO: Processing package[libpq-dev] action install (postgresql::client line 32)
[2013-07-24T17:05:52+00:00] INFO: Processing package[git] action install (git::default line 24)
[2013-07-24T17:05:55+00:00] INFO: Processing package[python] action install (python::package line 40)
[2013-07-24T17:05:55+00:00] INFO: Processing package[python-dev] action install (python::package line 40)
[2013-07-24T17:06:08+00:00] INFO: Processing remote_file[/tmp/vagrant-chef-1/distribute_setup.py] action create (python::pip line 40)
[2013-07-24T17:06:09+00:00] INFO: remote_file[/tmp/vagrant-chef-1/distribute_setup.py] updated
[2013-07-24T17:06:09+00:00] INFO: remote_file[/tmp/vagrant-chef-1/distribute_setup.py] mode changed to 644
[2013-07-24T17:06:09+00:00] INFO: Processing execute[install-pip] action run (python::pip line 46)
[2013-07-24T17:06:11+00:00] INFO: execute[install-pip] ran successfully
[2013-07-24T17:06:11+00:00] INFO: Processing python_pip[virtualenv] action install (python::virtualenv line 23)
[2013-07-24T17:06:11+00:00] INFO: Installing python_pip[virtualenv] version latest
[2013-07-24T17:06:11+00:00] INFO: Processing package[postgresql-9.1] action install (pybossa::default line 1)
[2013-07-24T17:06:18+00:00] INFO: Processing package[postgresql-server-dev-9.1] action install (pybossa::default line 2)
[2013-07-24T17:06:18+00:00] INFO: Processing package[python-dev] action install (pybossa::default line 3)
[2013-07-24T17:06:18+00:00] INFO: Processing python_virtualenv[/vagrant/vagrant_env] action create (pybossa::default line 5)
[2013-07-24T17:06:18+00:00] INFO: Creating virtualenv python_virtualenv[/vagrant/vagrant_env] at /vagrant/vagrant_env
[2013-07-24T17:06:18+00:00] INFO: Processing execute[virtualenv --python=python  /vagrant/vagrant_env] action run (/tmp/vagrant-chef-1/chef-solo-1/cookbooks/python/providers/virtualenv.rb line 32)

================================================================================

Error executing action `run` on resource 'execute[virtualenv --python=python  /vagrant/vagrant_env]'

================================================================================


Mixlib::ShellOut::ShellCommandFailed

------------------------------------

Expected process to exit with [0], but received '1'
---- Begin output of virtualenv --python=python  /vagrant/vagrant_env ----
STDOUT: Already using interpreter /usr/bin/python
New python executable in /vagrant/vagrant_env/bin/python
STDERR: Traceback (most recent call last):
  File "/usr/local/bin/virtualenv", line 9, in <module>
    load_entry_point('virtualenv==1.10', 'console_scripts', 'virtualenv')()
  File "/usr/local/lib/python2.7/dist-packages/virtualenv.py", line 821, in main
    symlink=options.symlink)
  File "/usr/local/lib/python2.7/dist-packages/virtualenv.py", line 956, in create_environment
    site_packages=site_packages, clear=clear, symlink=symlink))
  File "/usr/local/lib/python2.7/dist-packages/virtualenv.py", line 1375, in install_python
    os.symlink(py_executable_base, full_pth)
OSError: [Errno 71] Protocol error
---- End output of virtualenv --python=python  /vagrant/vagrant_env ----
Ran virtualenv --python=python  /vagrant/vagrant_env returned 1


Resource Declaration:

---------------------

# In /tmp/vagrant-chef-1/chef-solo-1/cookbooks/python/providers/virtualenv.rb

 31:     Chef::Log.info("Creating virtualenv #{new_resource} at #{new_resource.path}")
 32:     execute "#{virtualenv_cmd} --python=#{new_resource.interpreter} #{new_resource.options} #{new_resource.path}" do
 33:       user new_resource.owner if new_resource.owner
 34:       group new_resource.group if new_resource.group
 35:     end
 36:     new_resource.updated_by_last_action(true)

Compiled Resource:

------------------

# Declared in /tmp/vagrant-chef-1/chef-solo-1/cookbooks/python/providers/virtualenv.rb:32:in `class_from_file'

execute("virtualenv --python=python  /vagrant/vagrant_env") do
  retry_delay 2
  returns 0
  command "virtualenv --python=python  /vagrant/vagrant_env"
  retries 0
  action "run"
  cookbook_name :pybossa
  backup 5
end

[2013-07-24T17:06:19+00:00] ERROR: Running exception handlers
[2013-07-24T17:06:19+00:00] ERROR: Exception handlers complete
[2013-07-24T17:06:19+00:00] FATAL: Stacktrace dumped to /tmp/vagrant-chef-1/chef-stacktrace.out
[2013-07-24T17:06:19+00:00] FATAL: Mixlib::ShellOut::ShellCommandFailed: execute[virtualenv --python=python  /vagrant/vagrant_env] (/tmp/vagrant-chef-1/chef-solo-1/cookbooks/python/providers/virtualenv.rb line 32) had an error: Mixlib::ShellOut::ShellCommandFailed: Expected process to exit with [0], but received '1'
---- Begin output of virtualenv --python=python  /vagrant/vagrant_env ----
STDOUT: Already using interpreter /usr/bin/python
New python executable in /vagrant/vagrant_env/bin/python
STDERR: Traceback (most recent call last):
  File "/usr/local/bin/virtualenv", line 9, in <module>
    load_entry_point('virtualenv==1.10', 'console_scripts', 'virtualenv')()
  File "/usr/local/lib/python2.7/dist-packages/virtualenv.py", line 821, in main
    symlink=options.symlink)
  File "/usr/local/lib/python2.7/dist-packages/virtualenv.py", line 956, in create_environment
    site_packages=site_packages, clear=clear, symlink=symlink))
  File "/usr/local/lib/python2.7/dist-packages/virtualenv.py", line 1375, in install_python
    os.symlink(py_executable_base, full_pth)
OSError: [Errno 71] Protocol error
---- End output of virtualenv --python=python  /vagrant/vagrant_env ----
Ran virtualenv --python=python  /vagrant/vagrant_env returned 1
Chef never successfully completed! Any errors should be visible in the
output above. Please fix your recipes so that they properly complete.

[teleyinex]

Hi,

I don't know why is failing to create now the virtualenv. Can you completely destroy the vm and try again? You can even remove your .vagrant.d folder in your home directory (if you are in GNU/Linux) to start from scratch. Copy that folder to another location, to have a backup. Let me know what happens. I'll try to test it in another system, as it is working for me really. Question: which VirtualBox are you using? I'm using 4.2.16.

[ryanjarvis]

The issue is probably because I am building everything on a Windows machine.

The links in my last post suggest two things:

1. Python's virtualenv uses symbolic links in order to work
2. Vagrant by default sets up "/vagrant/vagrant_env" to use VirtualBox's shared folder filesystem, which may or may not support sym links

Because /vagrant/vagrant_env is a shared folder, it will follow the rules of the host operating system that you are using Vagrant/VirtualBox on. If you are building your project on a GNU/Linux system, you won't see my error since your host operating system supports sym links. However, since I am building on a Windows box, you won't be able to add sym links to /vagrant/vagrant_env. (which is what virtualenv is trying to do on line 5 of your pybossa.rb recipe)

So the way I see it, you have two solutions:

1. Either try and figure out how to get /vagrant/vagrant_env to permit python virtualenv to create sym links regardless of what OS you are building on (Windows, Mac or Linux)
2. Or change Pybossa so you aren't building in /vagrant/vagrant_env. Instead create a python virtualenv in some other folder in the VM that is NOT shared and change your web server to server from that folder instead.

If you do not have access to a Windows machine, I am happy to be your guinea pig. Perhaps you should set up a branch for Windows testing.

[ryanjarvis]

Oh and yes I am using VirtualBox 4.2.16. And am also building on Windows 7, which I probably should have stated at the start of this conversation. :-)

[ryanjarvis]

Ok, I got it to work. I can confirm that changing the directory that you install python virtualenv solves the problem. (I had it install in /opt/python) Once that happens, Chef completes all recipes successfully and you have Pybossa in a VM.

I would submit a pull request, but I don't know if you want to use my solution or not.

[teleyinex]

Hi,

Thanks for confirming the solution, and yes I like your solution. Please, test this branch which has the fix. If it works for you, in Linux works, I'll merge it. Next time, just send the pull-request ;-)

[teleyinex]

Closing it, as the pull requests works again.

[mkoryak]

Found this on google... The reason for the failed symlink is not because the mounted dir was on windows, but because you cannot symlink into a remote mount regardless of the OS.

[teleyinex]

+1 @mkoryak Now it is fixed and running :-)