Machine Creation Fails even though it succeeds - indications of vzeventd failing with error 79

[GoogleCodeExporter]

Steps to reproduce:
1. Install on centos 5.6, x86_64
2. Install official fedora14 x86_64 os template via interface.
3. create fedora14 guest

Actual result:
Web panel indicates error creating machine even though it succeeds in creating 
the machine. Message says to check the logs, snippet attached below.
I am getting this error with all OS templates.  It  does seem to succeed 
intermittently. 

Expected result:
Machine created without error.

Version of the product:
latest - installed via one-liner offered on the front page.

Server OS:
Centos 5.6 64bit

Browser:
Firefox

Additional information:

Logs from vzctl.log : ( note failed vzeventd pid was attempting to stop the 
containter ) 
--
2011-05-03T10:30:47-0400 vzctl : CT 101 : Creating container private area 
(fedora-14-x86_64)
2011-05-03T10:33:03-0400 vzctl : CT 101 : Performing postcreate actions
2011-05-03T10:33:05-0400 vzctl : CT 101 : Container private area was created
2011-05-03T10:33:05-0400 vzctl : CT 101 : Saved parameters for CT 101
2011-05-03T10:33:05-0400 vzctl : CT 101 : Saved parameters for CT 101
2011-05-03T10:33:05-0400 vzctl : CT 101 : Starting container ...
2011-05-03T10:33:05-0400 vzctl : CT 101 : Container is mounted
2011-05-03T10:33:06-0400 vzeventd : CT 101 : CTID = 101, event = ve-start 
(len=8)
2011-05-03T10:33:06-0400 vzeventd : CT 101 : Got start event (ignored)
2011-05-03T10:33:06-0400 vzctl : CT 101 : Container start in progress...
2011-05-03T10:33:09-0400 vzctl : CT 101 : Stopping container ...
2011-05-03T10:33:09-0400 vzeventd : CT 101 : CTID = 101, event = ve-stop (len=7)
2011-05-03T10:33:09-0400 vzeventd : CT 101 : Running stop event script
2011-05-03T10:33:09-0400 vzeventd : CT 101 : Running: 
/usr/lib64/vzctl/scripts/vzevent-stop 
2011-05-03T10:33:09-0400 vzeventd : CT 101 : Forked child 8320 for stop event
2011-05-03T10:33:09-0400 vzctl : CT 101 : Container was stopped
2011-05-03T10:33:09-0400 vzctl : CT 101 : Container is unmounted
2011-05-03T10:33:09-0400 vzctl : CT 101 : Saved parameters for CT 101
2011-05-03T10:33:09-0400 vzctl : CT 101 : Saved parameters for CT 101
2011-05-03T10:33:09-0400 vzctl : CT 101 : Saved parameters for CT 101
2011-05-03T10:33:09-0400 vzctl : CT 101 : Saved parameters for CT 101
2011-05-03T10:33:09-0400 vzctl : CT 101 : Saved parameters for CT 101
2011-05-03T10:33:09-0400 vzctl : CT 101 : Saved parameters for CT 101
2011-05-03T10:33:09-0400 vzctl : CT 101 : Starting container ...
2011-05-03T10:33:09-0400 vzctl : CT 101 : Container is mounted
2011-05-03T10:33:10-0400 vzeventd : CT 101 : CTID = 101, event = ve-start 
(len=8)
2011-05-03T10:33:10-0400 vzeventd : CT 101 : Got start event (ignored)
2011-05-03T10:33:10-0400 vzctl : CT 101 : Adding IP address(es): 192.168.5.230
2011-05-03T10:33:11-0400 vzctl : CT 101 : Setting CPU units: 1000
2011-05-03T10:33:11-0400 vzctl : CT 101 : Set hostname: test
2011-05-03T10:33:11-0400 vzctl : CT 101 : File resolv.conf was modified
2011-05-03T10:33:11-0400 vzctl : CT 101 : Container start in progress...
2011-05-03T10:34:04-0400 vzeventd : Child 8320 failed with exit code 79
--

Logs from production.log : 
--
Processing Admin::VirtualServersController#create (for x.x.x.x at 2011-05-03 
10:30:47) [POST]
  Parameters: {"cpus"=>"", "identity"=>"101", "orig_os_template"=>"fedora-14-x86_64", "memory"=>"272", "expiration_date"=>"", "orig_server_template"=>"basic", "host_name"=>"test", "diskspace"=>"1126", "cpu_units"=>"1000", "start_after_creation"=>"on", "password_confirmation"=>"[FILTERED]", "action"=>"create", "hardware_server_id"=>"1", "cpu_limit"=>"", "id"=>"", "search_domain"=>"me.here.com", "controller"=>"admin/virtual_servers", "description"=>"", "nameserver"=>"192.168.5.2", "user_id"=>"", "password"=>"[FILTERED]", "ip_address"=>"192.168.5.230", "start_on_boot"=>"on"}
Executing command: vzctl create 101 --ostemplate fedora-14-x86_64 --config basic
Executing command: vzctl set 101 --applyconfig basic --save
Executing command: vzctl set 101 --hostname test --save
Executing command: vzctl set 101 --userpasswd root:notonyerlife
Executing command: vzctl set 101 --nameserver 192.168.5.2 --save
Executing command: vzctl set 101 --searchdomain 'mehere.com' --save
Executing command: vzctl set 101 --cpuunits 1000 --save
Executing command: vzctl set 101 --ipadd 192.168.5.230 --save
Executing command: vzctl set 101 --privvmpages 69632 --save
Executing command: vzctl set 101 --diskspace 1153024 --save
Executing command: vzctl start 101
Virtual server 101 was created.
Completed in 144571ms (View: 0, DB: 28) | 200 OK 
[http://centosvz.mehere.com/admin/virtual-servers/create?hardware_server_id=1]

Original issue reported on code.google.com by pduboi...@gmail.com on 3 May 2011 at 2:54

[GoogleCodeExporter]

Additional information : 

Running htop on the host during a machine creation showed that the error popped 
up in my browser while the guest was still unpacking.   The logs indicate the 
guest completed it's install 'normally' but the web interface  decided an error 
had occurred.

Could this be a timeout issue?

Original comment by pduboi...@gmail.com on 3 May 2011 at 3:04

[GoogleCodeExporter]

Just installed the ubuntu-8.04-x86_64 os template with the assumption that this 
issue is timeout related.

the smaller template (compared to the fedora14 template) should result in 
quicker untar time and - in theory - no error.

Results : 

No Error!  

So - We have what appears to be a timeout issue when unpacking larger 
ostemplates on possibly io-challanged machines.

Can we extend this timeout ? I'm unfamiliar with the code and am unable to find 
where the machines are generated.

Original comment by pduboi...@gmail.com on 3 May 2011 at 3:46

[GoogleCodeExporter]

I'm not sure that problem is related to timeout. Error 79 means "Container 
action script returned an error" and it is reported by vzctl not by the panel 
itself. Looks like you have some problems with your OpenVZ installation. Try to 
create container manually using vzctl utility to confirm this.

Original comment by sibprogrammer on 4 May 2011 at 3:26

• Added labels: Milestone-Release2.1

[GoogleCodeExporter]

I confirmed the OpenVZ host is capable of creating guests without issue.  I've 
created guests by hand as well as via the webpanel.

The openvz-web-panel does not pop an error if the guest tarball is below a 
certain size. I've noticed that the vzctl/vzeventd error may
not be associated with the web-panel error.   A log snippit from a 
successful-failure is included below.  Please note that in every case
the failed machine appears in the host's guest list and is fully functional.

I should probably remark that these tarballs are the 'official' templates 
installed via the panel.

Example of successful deployment :
--
2011-05-04T11:34:41-0400 vzctl : CT 101 : Creating container private area 
(ubuntu-8.04-x86_64)                       
2011-05-04T11:35:20-0400 vzctl : CT 101 : Performing postcreate actions         

2011-05-04T11:35:20-0400 vzctl : CT 101 : Container private area was created    

2011-05-04T11:35:20-0400 vzctl : CT 101 : Saved parameters for CT 101           

2011-05-04T11:35:20-0400 vzctl : CT 101 : Saved parameters for CT 101           

2011-05-04T11:35:20-0400 vzctl : CT 101 : Saved parameters for CT 101           

2011-05-04T11:35:20-0400 vzctl : CT 101 : Saved parameters for CT 101           

2011-05-04T11:35:20-0400 vzctl : CT 101 : Saved parameters for CT 101           

2011-05-04T11:35:20-0400 vzctl : CT 101 : Saved parameters for CT 101           

2011-05-04T11:35:20-0400 vzctl : CT 101 : Saved parameters for CT 101
2011-05-04T11:35:20-0400 vzctl : CT 101 : Saved parameters for CT 101
2011-05-04T11:35:20-0400 vzctl : CT 101 : Saved parameters for CT 101
2011-05-04T11:35:20-0400 vzctl : CT 101 : Saved parameters for CT 101
2011-05-04T11:35:20-0400 vzctl : CT 101 : Starting container ...
2011-05-04T11:35:20-0400 vzctl : CT 101 : Container is mounted
2011-05-04T11:35:20-0400 vzeventd : CT 101 : CTID = 101, event = ve-start 
(len=8)
2011-05-04T11:35:20-0400 vzeventd : CT 101 : Got start event (ignored)
2011-05-04T11:35:20-0400 vzctl : CT 101 : Adding IP address(es): 192.168.5.230
2011-05-04T11:35:22-0400 vzctl : CT 101 : Setting CPU limit: 50
2011-05-04T11:35:22-0400 vzctl : CT 101 : Setting CPU units: 1000
2011-05-04T11:35:22-0400 vzctl : CT 101 : Setting CPUs: 2
2011-05-04T11:35:22-0400 vzctl : CT 101 : Set hostname: testtesttest
2011-05-04T11:35:22-0400 vzctl : CT 101 : File resolv.conf was modified
2011-05-04T11:35:22-0400 vzctl : CT 101 : Container start in progress...
--

Example of a successful deployment that popped an error via the web panel :  
( The error popped up before the container was done untaring, represented by 
the empty line #2)
--
2011-05-04T11:40:27-0400 vzctl : CT 103 : Creating container private area 
(suse-11.3-x86_64)

2011-05-04T11:41:45-0400 vzctl : CT 103 : Performing postcreate actions
2011-05-04T11:41:46-0400 vzctl : CT 103 : Container private area was created
2011-05-04T11:41:46-0400 vzctl : CT 103 : Saved parameters for CT 103
2011-05-04T11:41:46-0400 vzctl : CT 103 : Saved parameters for CT 103
2011-05-04T11:41:46-0400 vzctl : CT 103 : Saved parameters for CT 103
2011-05-04T11:41:46-0400 vzctl : CT 103 : Saved parameters for CT 103
2011-05-04T11:41:46-0400 vzctl : CT 103 : Saved parameters for CT 103
2011-05-04T11:41:46-0400 vzctl : CT 103 : Saved parameters for CT 103
2011-05-04T11:41:46-0400 vzctl : CT 103 : Saved parameters for CT 103
2011-05-04T11:41:47-0400 vzctl : CT 103 : Saved parameters for CT 103
2011-05-04T11:41:47-0400 vzctl : CT 103 : Saved parameters for CT 103
2011-05-04T11:41:47-0400 vzctl : CT 103 : Saved parameters for CT 103
2011-05-04T11:41:47-0400 vzctl : CT 103 : Starting container ...
2011-05-04T11:41:47-0400 vzctl : CT 103 : Container is mounted
2011-05-04T11:41:47-0400 vzeventd : CT 103 : CTID = 103, event = ve-start 
(len=8)
2011-05-04T11:41:47-0400 vzeventd : CT 103 : Got start event (ignored)
2011-05-04T11:41:47-0400 vzctl : CT 103 : Adding IP address(es): 192.168.5.232
2011-05-04T11:41:50-0400 vzctl : CT 103 : Setting CPU limit: 50
2011-05-04T11:41:50-0400 vzctl : CT 103 : Setting CPU units: 1000
2011-05-04T11:41:50-0400 vzctl : CT 103 : Setting CPUs: 2
2011-05-04T11:41:50-0400 vzctl : CT 103 : Set hostname: suse11.3
2011-05-04T11:41:50-0400 vzctl : CT 103 : File resolv.conf was modified
2011-05-04T11:41:50-0400 vzctl : CT 103 : Container start in progress...
--

Thank you for the help!

Patrick Dubois.

Original comment by pduboi...@gmail.com on 4 May 2011 at 4:07

[GoogleCodeExporter]

Just to give you an idea of what kind of execution time it takes for deploying 
the fedora14 container : 

--
[root@centosvz ~]# time vzctl create 111 --ostemplate fedora-14-x86_64 --config 
mehere.com
Creating container private area (fedora-14-x86_64)
Performing postcreate actions
Container private area was created

real    1m25.744s
user    0m12.927s
sys     0m6.492s
[root@centosvz ~]# 
--

Tests indicate the error pops up at exactly 60 seconds every time.

I suspect that the xmlrpc operations timeout at 60 seconds.

Thanks again!

Patrick Dubois.

Original comment by pduboi...@gmail.com on 4 May 2011 at 4:23

[GoogleCodeExporter]

Additional information : 

The errors reported by vzeventd do not seem to be related to the panel popping 
errors after a 60 second wait.

My apologies for the misleading issue subject line. 

Original comment by pduboi...@gmail.com on 4 May 2011 at 5:56

[GoogleCodeExporter]

Closing issue, 'cause nothing to do with panel itself.

Original comment by sibprogrammer on 9 May 2011 at 3:42

• Changed state: Done

[GoogleCodeExporter]

After reviewing several aspects of the panel's operation I started to get 
curious about anything else that could cause this.

Discovered the reverse proxy using a timeout of 60 seconds. value doubled to 
120 seconds, error disappears. 

So - confirmed the panel itself was not the cause of the issue.  Will look into 
improving the error message however.

Original comment by pduboi...@gmail.com on 9 May 2011 at 6:02