mitchellh / virtualbox

[ABANDONED] Create and modify virtual machines in VirtualBox using pure ruby.
http://mitchellh.github.com/virtualbox/
MIT License
245 stars 45 forks source link

Every now and then I get the: "Error in API call to FFI..." #25

Closed jeroenvandijk closed 14 years ago

jeroenvandijk commented 14 years ago

I get this error every now and then. When I rerun my command it mostly does not reoccur, so consider this a minor issue.

From what I remember I get this error with the Vagrant commands 'ssh, reload, destroy':

As you may remember, I'm running Mac osx 10.5.8

Here is the complete error trace:

      vagrant reload

[INFO 04-19-2010 09:35:46] Vagrant: Provisioning enabled with Vagrant::Provisioners::ChefSolo [INFO 04-19-2010 09:35:46] Vagrant: Forcing shutdown of VM... [INFO 04-19-2010 09:35:47] Vagrant: Running any VM customizations... /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/virtualbox-0.6.0/lib/virtualbox/com/implementer/ffi.rb:97:in call_and_check': Error in API call to #<FFI::Function:0x1c8fc84>: 2159738887 (VirtualBox::Exceptions::InvalidObjectStateException) from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/virtualbox-0.6.0/lib/virtualbox/com/implementer/ffi.rb:71:incall_vtbl_function' from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/virtualbox-0.6.0/lib/virtualbox/com/implementer/ffi.rb:52:in call_function' from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/virtualbox-0.6.0/lib/virtualbox/com/abstract_interface.rb:132:incall_function' from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/virtualbox-0.6.0/lib/virtualbox/com/abstract_interface.rb:50:in open_session' from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/virtualbox-0.6.0/lib/virtualbox/vm.rb:254:inwith_open_session' from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/virtualbox-0.6.0/lib/virtualbox/vm.rb:228:in save' from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/vagrant-0.3.0/lib/vagrant/actions/vm/customize.rb:12:inexecute!' from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/vagrant-0.3.0/lib/vagrant/actions/runner.rb:86:in send' from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/vagrant-0.3.0/lib/vagrant/actions/runner.rb:86:inexecute!' from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/vagrant-0.3.0/lib/vagrant/actions/runner.rb:85:in each' from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/vagrant-0.3.0/lib/vagrant/actions/runner.rb:85:inexecute!' from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/vagrant-0.3.0/lib/vagrant/actions/runner.rb:84:in each' from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/vagrant-0.3.0/lib/vagrant/actions/runner.rb:84:inexecute!' from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/vagrant-0.3.0/lib/vagrant/commands/reload.rb:14:in execute' from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/vagrant-0.3.0/lib/vagrant/commands/base.rb:41:indispatch' from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/vagrant-0.3.0/lib/vagrant/commands/base.rb:50:in dispatch' from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/vagrant-0.3.0/lib/vagrant/command.rb:24:insubcommand' from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/vagrant-0.3.0/lib/vagrant/command.rb:13:in execute' from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/gems/vagrant-0.3.0/bin/vagrant:7 from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/bin/vagrant:19:inload' from /Users/jvandijk/.rvm/gems/ruby-1.8.7-p174/bin/vagrant:19

mitchellh commented 14 years ago

jeroen,

You're right. I can easily repeat this on my end as well. I'm looking into it.

Mitchell

mitchellh commented 14 years ago

jeroen,

I think I already told you this in IRC but I did want to note that this issue in Vagrant has been fixed. However, this is a really a fix that should be done upstream here in VirtualBox so I'll be on the lookout as to what may be causing this.

Mitchell

jeroenvandijk commented 14 years ago

Hi Mitchell,

Thanks, for fixing. I guess it is a really difficult issue, because it only occurs once in a while. Maybe even depending on the state of my machine, at least that's how it feels :)

Jeroen

lastobelus commented 14 years ago

I wonder if this is related to .vmdk files getting orphaned?

mitchellh commented 14 years ago

I believe its due to the fact that vagrant reload attempts to save the VM information before the VM is truly "powered off." I thought that the "stop" method was supposed to block until its shut down but it looks like there is a very small overlap where it returns but the VM is not yet truly stopped.

I'm still trying to figure this one out.

mitchellh commented 14 years ago

Finally! This issue has been fixed. Really strange but it happened to do with how I was handling "sessions" within the VirtualBox gem. Sessions are a low-level locking mechanism which VirtualBox uses to ensure mutual exclusion while modifying machines.

It turned out I was making some mistakes when closing these sessions, which caused the above FFI exception.

These "mistakes" don't cause any damage or issues with VirtualBox other than the above exception and setting the state of the VM to "aborted."

This issue will be completely gone in the next release of this gem. Hurray!

Mitchell

mitchellh commented 14 years ago

(And for the curious, I actually found this bug only because while I was working on snapshotting, it manifested itself in an easily repeatable manner. After that it was only moments before the bug was squashed)

jeroenvandijk commented 14 years ago

Very nice! Yesterday I had some problems with Virtualbox and the bug appeared more often for some reason. Happy to see this fixed!

Jeroen

jedi4ever commented 13 years ago

I use 0.7.5 version and seem to hit this problem quite often.

Whenever I hit this problem, there seems to be a pipe running like this /Applications/VirtualBox.app/Contents/MacOS/VBoxSVC --pipe 6 --auto-shutdown

When I kill it it works again. Strange...