API debug: Vagrant-proxmox and LXC = 400 Bad Request

Jan 21, 2016
96
8
73
43
Germany
www.pug.org
hi,

we want to use Vagrant to create VMs on our Proxmox 4.1 cluster (with ZFS). So we use the vagrant-proxmox plugin, which works with KVM.
If I try to get the same working with LXC, than I get a "400 Bad Request". I have no idea, how to debug on the Proxmox side. Is there a debug option, to see, what is wrong with the JSON ?
 
Does the vagrant plugin support LXC now? As I know a few months ago it did not.
Can you post which API URL it tries to access?

Those two could be helpful when debugging the API:
https://<PVE-IP>:8006/api2/html/
https://<PVE-IP>:8006/api2/json/

Maybe open an issue at the plugins github site? As the plugin is not maintained by Proxmox, although we try to help if possible as I'm very limited experience with vagrant for now.
 
  • Like
Reactions: Denny Fuchs
Sorry if I over see it, but where is you storage configuration in the Vagrant config? Or does Vagrant omits parameter if there is now value configured?
Because the vagrant create_vm LXC create part uses
Code:
storage: "#{config.vm_storage}:#{config.vm_disk_size}",

and if that is not configured and it send an empty storage param to the API it would result in "400 Bad request"
Try adding storage to your vagrant cfg, use local if you want the default or the respective ZPool.

As I said I do not know vagrant that much but that could be the problem.
 
I think, you mean the missing lines:

proxmox.vm_storage = 'pve-container'
proxmox.vm_disk_size = '5G'


It was missing in my Github question, but adding it to the Vagrantfile doesn't help.

So I have now:
Code:
Vagrant.configure('2') do |config|
  config.vm.provider :proxmox do |proxmox|
  proxmox.endpoint = 'https://pmox-01:8006/api2/json'
  proxmox.user_name = 'vagrant'
  proxmox.password = 'xxxxx'
  proxmox.vm_id_range = 900..999
  proxmox.vm_storage = 'pve-container'
  proxmox.vm_disk_sze = '5G'
  proxmox.vm_name_prefix = 'vagrant_'
  proxmox.openvz_os_template = '/var/lib/vz/template/cache/lxc-template.tar.gz'
  proxmox.vm_type = :lxc
  proxmox.vm_memory = 512
  end

  config.vm.define :box, primary: true do |box|
  box.vm.box = 'dummy'
  box.vm.network :public_network, ip: '145.4.191.18', interface: 'eth0', bridge: 'vmbr1', gw: '159.39.33.254'
  end
end
 
Hmm damn, would been to easy...

Is on the PVE server side anything in:
less /var/log/pveproxy/access.log

We do not store the params in there so it is not that useful for debugging that but still...

I look if I can fireup a vagrant instance and try that, any recommendation how to get that running as fastest possible for this testcase?
 
The fast way:

  • wget https://releases.hashicorp.com/vagrant/1.8.1/vagrant_1.8.1_x86_64.deb && sudo dpkg -i vagrant_1.8.1_x86_64.deb
  • vagrant plugin install vagrant-proxmox
  • Download default LXC template in /var/lib/vz/template/cache -> debian-8.0-standard_8.0-1_amd64.tar.gz
  • mkdir vagrant && cd vagrant (only cleanup)
  • git clone https://github.com/telcat/vagrant-proxmox
  • cp -a vagrant-proxmox/dummy_box .
  • vagrant box add dummy dummy_box/dummy.box
  • <create Vagrantfile and change os_template to debian-8.0-standard_8.0-1_amd64.tar.gz>
  • vagrant --debug up --provider=proxmox
 
Ok, changed the line ... should I also change anything in the Vagrantfile?

Vagrant.configure('2') do |config|
config.vm.provider :proxmox do |proxmox|
proxmox.endpoint = 'https://pmox01:8006/api2/json'
proxmox.user_name = 'xxxxxxxx'
proxmox.password = 'yyyyyyyy'
proxmox.vm_id_range = 900..999
proxmox.vm_name_prefix = 'vagrant_'
proxmox.openvz_os_template = '/var/lib/vz/template/cache/debian-8.0-standard_8.0-1_amd64.tar.gz'
proxmox.vm_type = :lxc
proxmox.vm_memory = 512
proxmox.vm_storage = 'pve-container'
proxmox.vm_disk_size = '5G'
end

config.vm.define :box, primary: true do |box|
box.vm.box = 'dummy'
box.vm.network :public_network, ip: '1.2.4.3', bridge: 'vmbr1'
end
end


[...]
/opt/vagrant/embedded/gems/gems/vagrant-1.8.1/lib/vagrant/machine.rb:185:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.8.1/lib/vagrant/machine.rb:185:in `action'
/opt/vagrant/embedded/gems/gems/vagrant-1.8.1/lib/vagrant/batch_action.rb:82:in `block (2 levels) in run'
INFO interface: error: Unable to communicate with proxmox server:

Unable to create the virtual machine!

Cause: 400 Bad Request
Unable to communicate with proxmox server:

Unable to create the virtual machine!

Cause: 400 Bad Request
 
It seems it still uses the old code as I with this I created multiple LXC CTs with no problem.
Hmm, are you sure you recompiled it with rake or changed it in the installation directly?

As I'm not very comfortable with ruby used build tools like rake I modified also the installation itself, which was located somewhere in ~/.vagrant/... (I did a " find -depth -name 'create_vm.rb' " to find the real path.)
 
hi,

hmm, harder than I tought ....

I compiled yesterday the plugin from the Github repo (with patches) ... it works with Qemu (tested again for sure :) ..), but it breaks with LXC. Maybe the problem is the underlying ZPool, or my Vagrantfile isn't O.K. Can you please give me your file?
 
Same error as previously?
Code:
Vagrant.configure('2') do |config|
   config.vm.provider :proxmox do |proxmox|
     proxmox.endpoint = 'https://192.168.15.57:8006/api2/json'
     proxmox.user_name = 'root@pam'
     proxmox.password = '12345'
     proxmox.vm_type = :lxc
     proxmox.openvz_os_template = '/var/lib/vz/template/cache/debian-8.0-standard_8.0-1_amd64.tar.gz'
     proxmox.vm_id_range = 9000..9010
     proxmox.vm_disk_size = '5G'
     proxmox.vm_storage = 'tom_nasi'
     proxmox.vm_name_prefix = 'vagrant_'
     proxmox.vm_memory = 512
   end

   config.vm.define :box, primary: true do |box|
     box.vm.box = 'dummy'
     box.vm.network :public_network, ip: '192.168.15.61', interface: 'eth0', bridge: 'vmbr0', gw: '192.168.15.1'
   end

end

I have to note that as I had no vagrant template available which listens on a specific port vagrant could not finish completely, but the CT was successfully created and I could start it and login with the vagrant credentials.
 
Last edited:
hi,

took your Vagrant file first 1:1 (changed user/pw/url) and nearly the same:

INFO runner: Running action: machine_action_up #<Vagrant::Action::Warden:0x00000002f9d308>
INFO warden: Calling IN action: #<Proc:0x00000002e9fc30@/opt/vagrant/embedded/gems/gems/vagrant-1.8.1/lib/vagrant/action/warden.rb:94 (lambda)>
INFO warden: Calling IN action: #<VagrantPlugins::proxmox::Action::CreateVm:0x00000002f9d290>
INFO interface: info: Creating the virtual machine...
INFO interface: info: ==> box: Creating the virtual machine...
==> box: Creating the virtual machine...
ERROR warden: Error occurred: Unable to create the virtual machine!

Cause: VagrantPlugins::proxmox::ApiError::ServerError
INFO warden: Beginning recovery process...
INFO warden: Recovery complete.
ERROR warden: Error occurred: Unable to create the virtual machine
!
[...]
/opt/vagrant/embedded/gems/gems/vagrant-1.8.1/lib/vagrant/machine.rb:185:in `call'
/opt/vagrant/embedded/gems/gems/vagrant-1.8.1/lib/vagrant/machine.rb:185:in `action'
/opt/vagrant/embedded/gems/gems/vagrant-1.8.1/lib/vagrant/batch_action.rb:82:in `block (2 levels) in run'
INFO interface: error: Unable to communicate with proxmox server:

Unable to create the virtual machine!

Cause: VagrantPlugins::proxmox::ApiError::ServerError
Unable to communicate with proxmox server:

Unable to create the virtual machine!

Cause: VagrantPlugins::proxmox::ApiError::ServerError
INFO interface: Machine: error-exit ["VagrantPlugins::proxmox::Errors::CommunicationError", "Unable to communicate with proxmox server:\n\nUnable to create the virtual machine!\n\nCause: VagrantPlugins::proxmox::ApiError::ServerError"]


Also changing from local to pve-container (zpool) doesn't help. I've created the LXC manually ..

{
"data" : {
"digest" : "fd1d9b2d3e829a3763a200465f6e64dd1ce3ad5b",
"cpulimit" : "1",
"ostype" : "debian",
"cpuunits" : 1024,
"net0" : "bridge=vmbr1,hwaddr=62:31:33:38:38:64,ip=192.168.15.61/24,name=eth0,type=veth",
"arch" : "amd64",
"rootfs" : "pve-container:subvol-117-disk-1,size=8G",
"swap" : 512,
"memory" : 512,
"hostname" : "bla2"
}
}


(get via :8006/html URL).

Since I can't deactivate HTTPs, debugging is much harder :)

pveproxy log:

[...]
10.0.0.4 - vagrant@pve [20/Apr/2016:12:57:11 +0200] "GET /api2/json/nodes/pmox01/lxc/117/status/current HTTP/1.1" 200 260
172.25.50.34 - - [20/Apr/2016:12:57:16 +0200] "POST /api2/json/access/ticket HTTP/1.1" 200 641
172.25.50.34 - - [20/Apr/2016:12:57:16 +0200] "POST /api2/json/access/ticket HTTP/1.1" 200 642
172.25.50.34 - - [20/Apr/2016:12:57:16 +0200] "POST /api2/json/access/ticket HTTP/1.1" 200 646
172.25.50.34 - - [20/Apr/2016:12:57:16 +0200] "POST /api2/json/access/ticket HTTP/1.1" 200 645
172.25.50.34 - vagrant@pve [20/Apr/2016:12:57:16 +0200] "GET /api2/json/nodes HTTP/1.1" 200 833
10.0.0.4 - vagrant@pve [20/Apr/2016:12:57:16 +0200] "GET /api2/json/nodes/pmox01/lxc/117/status/current HTTP/1.1" 200 260
172.25.50.34 - vagrant@pve [20/Apr/2016:12:57:20 +0200] "GET /api2/json/cluster/resources?type=vm HTTP/1.1" 200 1512
172.25.50.34 - vagrant@pve [20/Apr/2016:12:57:20 +0200] "POST /api2/json/nodes/pmox01/lxc HTTP/1.1" 500 13
10.0.0.4 - vagrant@pve [20/Apr/2016:12:57:21 +0200] "GET /api2/json/nodes/pmox01/lxc/117/status/current HTTP/1.1" 200 260
10.0.0.4 - vagrant@pve [20/Apr/2016:12:57:26 +0200] "GET /api2/json/nodes/pmox01/lxc/117/status/current HTTP/1.1" 200 260
[...]


So I can see a "500'er" error, following by 13 ...

 
Hmm, ok but this is another error than the 400 previously...

In my case if I do not apply my pull reuqest I get a 400-error if I apply it container creation works like a charm, strange.

Regarding the log: 13 just means the content length in this case.

For more debug options you could add a line of code if you want. Open /usr/share/perl5/PVE/HTTPServer.pm on line 130 in the log_request method add:
Code:
$msg .= Dumper($reqstate) if $code != 200;

I appended a patch which does that load it on the node and do
Code:
cd /usr/share/perl5/
patch -p1 </path/to/my.patch
systemctl restart pveproxy

This will add quite some additional stuff to the log on requests which are not successful.
After that exec a vagrant call and look in the logs, at best post the output to me/here for further debugging.

If you applied my patch and want to remove it you can reverse it with:
Code:
cd /usr/share/perl5/
patch -R -p1 </path/to/my.patch
systemctl restart pveproxy
 

Attachments

  • HTTPServer_debuglog.txt
    343 bytes · Views: 9
hi,

debug like a PRO :-D

created a stunnel ... and removed https ;-)


E.....@.@.....2"..2".i"...|j.2L.P..V.>..POST /api2/json/nodes/pmox01/lxc HTTP/1.1
Accept: */*; q=0.5, application/xml
Accept-Encoding: gzip, deflate
Csrfpreventiontoken: 57176E25:SZDUtTe4PRV7gPLt5O1uUGttaDA
Cookie: PVEAuthCookie=PVE:vagrant@pve<secret>
Content-Length: 191
Content-Type: application/x-www-form-urlencoded
User-Agent: Ruby
Host: 172.25.50.34:8888


13:55:21.279062 IP devpc.8888 > devpc.34409: Flags [.], ack 686, win 353, length 0
E..(..@.@.....2"..2""..i.2L.....P..a....
13:55:21.279081 IP devpc.34409 > devpc21.8888: Flags [P.], seq 686:877, ack 1, win 342, length 191
E.....@.@.....2"..2".i"......2L.P..V.P..vmid=9000&ostemplate=&hostname=box&password=vagrant&rootfs=pve-container%3A1&memory=512&description=vagrant_box&net0=name%3Deth0%2Cip%3D192.168.15.61%2F24%2Cgw%3D192.168.15.1%2Cbridge%3Dvmbr1
13:55:21.279085 IP devpc.8888 > devpc.34409: Flags [.], ack 877, win 363, length 0
E..(..@.@.....2"..2""..i.2L.....P..k....
13:55:21.288477 IP devp.8888 > devpc.34409: Flags [P.], seq 1:363, ack 877, win 363, length 362
E.....@.@..[..2"..2""..i.2L.....P..k....HTTP/1.1 500 Only root can pass arbitrary filesystem paths. at /usr/share/perl5/PVE/RPCEnvironment.pm line 304.
Cache-Control: max-age=0
Connection: close
Date: Wed, 20 Apr 2016 11:55:21 GMT
Pragma: no-cache
Server: pve-api-daemon/3.0
Content-Length: 13
Content-Type: application/json;charset=UTF-8
Expires: Wed, 20 Apr 2016 11:55:21 GMT


Debug from pveproxy:

172.25.50.34 - vagrant@pve [20/Apr/2016:14:04:40 +0200] "GET /api2/json/cluster/resources?type=vm HTTP/1.1" 200 1542
172.25.50.34 - vagrant@pve [20/Apr/2016:14:04:40 +0200] "POST /api2/json/nodes/pmox01/lxc HTTP/1.1" 500 13
$VAR1 = {
'log' => {
'code' => 500,
'userid' => 'vagrant@pve',
'requestline' => 'POST /api2/json/nodes/pmox01/lxc HTTP/1.1',
'content_length' => 13,
'written' => 1
},
'request' => bless( {
'_content' => 'vmid=9000&ostemplate=&hostname=box&password=vagrant&rootfs=pve-container%3A1&memory=512&description=vagrant_box&net0=name%3Deth0%2Cip%3D192.168.15.61%2F24%2Cgw%3D192.168.15.1%2Cbridge%3Dvmbr1',
'_method' => 'POST',
'_headers' => bless( {
'accept-encoding' => 'gzip, deflate',
'content-type' => 'application/x-www-form-urlencoded',
'user-agent' => 'Ruby',
'host' => '172.25.50.34:8888',
'csrfpreventiontoken' => '57177055:flKnXTawRCPJdLE5SJndRKok4Rk',
'cookie' => 'PVEAuthCookie=PVE:vagrant@pve:57177055::<secret>',
'pveclientip' => '172.25.50.34',
'content-length' => '191',
'accept' => '*/*; q=0.5, application/xml',
'::std_case' => {
'cookie' => 'Cookie',
'pveclientip' => 'PVEClientIP',
'csrfpreventiontoken' => 'Csrfpreventiontoken',
'pvedisableproxy' => 'PVEDisableProxy'
}
}, 'HTTP::Headers' ),
'_uri' => bless( do{\(my $o = '/api2/json/nodes/pmox01/lxc')}, 'URI::_generic' )
}, 'HTTP::Request' ),
'peer_host' => '172.25.50.34',
'keep_alive' => 0,
'hdl' => bless( {
'tls_ctx' => bless( {
'verify_mode' => 0,
'ctx' => 112252432
}, 'AnyEvent::TLS' ),
'_tw' => bless( do{\(my $o = 'H�A��Ep�K�\\j<y��d9A')}, 'EV::Timer' ),
'rbuf' => '',
'_rw' => bless( do{\(my $o = 'H�A�.���N��E�\\j
')}, 'EV::IO' ),
'_wbio' => 122591184,
'fh' => bless( \*Symbol::GEN17, 'IO::Socket::IP' ),
'timeout' => 5,
'_activity' => '1461153880.15852',
'on_error' => sub { "DUMMY" },
'_ractivity' => '1461153880.11188',
'_wactivity' => '1461153880.11135',
'tls' => 122627248,
'on_eof' => sub { "DUMMY" },
'read_size' => 2048,
'wbuf' => '',
'_rbio' => 122418816,
'linger' => 0,
'oobinline' => 1,
'_queue' => [],
'rbuf_max' => 65536
}, 'AnyEvent::Handle' ),
'starttime' => [
1461153880,
111963
],
'peer_port' => 52485,
'proto' => {
'min' => '1',
'ver' => 1001,
'maj' => 1,
'str' => 'HTTP/1.1'
},
'accept_gzip' => 1
};
 
Last edited:
created a stunnel ... and removed https ;-)

ahaha, perfect! :D

used now "root@pam" for testing and it works :), but what is the problem with my user Vagrant ? I can create a LXC container manual as this user. So, maybe I found a bug? The role that inherits vagrant user is "Administrator".

Oh, damn so obvious! The problem is, as you may already seen in your log, that only root can pass a real path to the container creation call, else we would have a security problem.

In the vagrantfile replace:
Code:
proxmox.openvz_os_template = '/var/lib/vz/template/cache/debian-8.0-standard_8.0-1_amd64.tar.gz'
with:
Code:
proxmox.openvz_os_template = 'local:vztmpl/debian-8.0-standard_8.0-1_amd64.tar.gz'

You should not need to move the template file anywhere as local: point to this if pve wants to get a template.

Edit: But I recalled this only from memory, have to test it yet!
Doubleedit: Tested it now, worked for me :)
 
Last edited:

About

The Proxmox community has been around for many years and offers help and support for Proxmox VE, Proxmox Backup Server, and Proxmox Mail Gateway.
We think our community is one of the best thanks to people like you!

Get your subscription!

The Proxmox team works very hard to make sure you are running the best software and getting stable updates and security enhancements, as well as quick enterprise support. Tens of thousands of happy customers have a Proxmox subscription. Get yours easily in our online shop.

Buy now!