[vbox-dev] Unable to use restarted VBoxWebSrv

Thu Dec 19 15:00:35 UTC 2013

I am writing a virtual machine management front end in Java (Windows 8.1) using the java bindings included in the 4.3.4 SDK. Part of this front end monitors that the VBox processes are up and running by performing a getVersion on them every once in a while. If this call throws we look at the exception and will restart these processes (VBoxWebSrv & VBoxSVC) in an attempt to regain a sane connection again. When I tear things down, I call VirtualBoxManager.disconnect() and VirtualBoxManager.cleanup(). I then set my reference to the VirtualBoxManager to null and set my reference to the IVirtualBox to null (see below) 

VirtualBoxManager mgr; 
IVirtualBox vboxServer; 
ISession vmPlayerSession; 

vmPlayerSession.releaseRemote(); 

vboxServer.releaseRemote(); 

mgr.disconnect(); 
mgr.cleanup(); 

vboxServer = null; 
mgr = null; 
vmPlayerSession = null; 

I then re-launch the VBoxWebSrv (which launched the VBoxSVC) and then perform the startup/connect sequence: 

VirtualBoxManager mgr = VirtualBoxManager.createInstance(null); 
mgr.connect(VBOX_WEB_SERVER_URI, VBOX_WEB_SERVER_USER, VBOX_WEB_SERVER_PWD); 
vboxServer = mgr.getVBox(); 

The problem I'm seeing.... 
When I use this newly launched and connected VBoxWeb interface using the java bingings, the webserver seems to hang when I call findMachine. This in turn hangs my java app because it is sitting on the vboxWebServer socket waiting for a reply with an indefinite timeout (can this timeout be set in VBox config somewhere?). 

This only ever happens on a restart of the VBox processes from within my java app. It is as if the java bindings are not entirely cleaned up when I take things down. 

Am I missing something on the cleanup? 

My app stack trace. You can see it stuck on the socketRead 
------------------------------------------------------------- 

Thread [WorkUnit508] (Suspended) 
owns: BufferedInputStream (id=56) 
owns: HttpURLConnection (id=57) 
owns: Fiber (id=58) 
SocketInputStream.socketRead0(FileDescriptor, byte[], int, int, int) line: not available [native method] 
SocketInputStream.read(byte[], int, int, int) line: 152 
SocketInputStream.read(byte[], int, int) line: 122 
BufferedInputStream.fill() line: 235 
BufferedInputStream.read1(byte[], int, int) line: 275 
BufferedInputStream.read(byte[], int, int) line: 334 
HttpClient.parseHTTPHeader(MessageHeader, ProgressSource, HttpURLConnection) line: 687 
HttpClient.parseHTTP(MessageHeader, ProgressSource, HttpURLConnection) line: 633 
HttpURLConnection.getInputStream() line: 1323 
HttpURLConnection(HttpURLConnection).getResponseCode() line: 468 
HttpClientTransport.readResponseCodeAndMessage() line: 192 
HttpTransportPipe.createResponsePacket(Packet, HttpClientTransport) line: 212 
HttpTransportPipe.process(Packet) line: 203 
HttpTransportPipe.processRequest(Packet) line: 122 
DeferredTransportPipe.processRequest(Packet) line: 95 
Fiber.__doRun(Tube) line: 626 
Fiber._doRun(Tube) line: 585 
Fiber.doRun(Tube) line: 570 
Fiber.runSync(Tube, Packet) line: 467 
SEIStub(Stub).process(Packet, RequestContext, ResponseContextReceiver) line: 308 
SEIStub.doProcess(Packet, RequestContext, ResponseContextReceiver) line: 146 
SyncMethodHandler.invoke(Object, Object[], RequestContext, ResponseContextReceiver) line: 98 
SyncMethodHandler.invoke(Object, Object[]) line: 78 
SEIStub.invoke(Object, Method, Object[]) line: 129 
$Proxy33.iVirtualBoxFindMachine(String, String) line: not available 
IVirtualBox.findMachine(String) line: 850 
VirtualBoxPlayer.findMachine(String) line: 516 
VirtualBoxPlayer.startVirtualMachine(VmAppliance) line: 483 
VirtualBoxJob.call() line: 113 
VirtualBoxJob(Job).call() line: 1 
FutureTask<V>.run() line: 262 
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker) line: 1145 
ThreadPoolExecutor$Worker.run() line: 615 
Thread.run() line: 724 

The verbose logs from the VBoxWebSrv. It seems to be part way through its internal call to findMachine. 
--------------------------------------------------------------------------------------------------------- 

00:00:00.015011 main Package type: WINDOWS_64BITS_GENERIC 
00:00:00.432661 main Pumping COM event queue 
00:00:00.432661 Watchdog Watchdog thread started 
00:00:00.432661 Watchdog Watchdog: sleeping 5 seconds 
00:00:00.509351 SQPmp Socket connection successful: host = default (localhost), port = 18083, master socket = 704 
00:00:04.984021 SQPmp Request 1 on socket 840 queued for processing (1 items on Q) 
00:00:04.984021 SQW01 New SOAP thread started 
00:00:04.984021 SQW01 Processing connection from IP=127.0.0.1 socket=840 (0 out of 1 threads idle) 
00:00:04.984021 SQW01 -- entering __vbox__IWebsessionManager_USCORElogon 
00:00:04.988023 SQW01 external authentication library is 'null' 
00:00:04.989024 SQW01 * ManagedObjectRef::ManagedObjectRef: MOR created for ISession*=0x0000000137ce68 (IUnknown*=0x0000000137cdd8; COM refcount now 3/4), new ID is 1; now 1 objects total 
00:00:04.989024 SQW01 * WebServiceSession::authenticate: created session object with comptr 0x0000000137ce68, MOR = e3b14703552e6d85-0000000000000001 
00:00:04.989024 SQW01 * ManagedObjectRef::ManagedObjectRef: MOR created for IVirtualBox*=0x000000012855e8 (IUnknown*=0x00000001292748; COM refcount now 5/6), new ID is 2; now 2 objects total 
00:00:04.989024 SQW01 VirtualBox object ref is e3b14703552e6d85-0000000000000002 
00:00:04.989024 SQW01 -- leaving __vbox__IWebsessionManager_USCORElogon, rc: 0x0 
00:00:04.991026 SQW01 -- entering __vbox__IVirtualBox_USCOREgetVersion 
00:00:04.991026 SQW01 ManagedObjectRef::findRefFromId(): looking up objref e3b14703552e6d85-0000000000000002 
00:00:04.991026 SQW01 findComPtrFromId(): returning original IVirtualBox*=0x12855E8 (IUnknown*=0x1292748) 
00:00:04.991026 SQW01 calling COM method COMGETTER(Version) 
00:00:04.991026 SQW01 done calling COM method 
00:00:04.991026 SQW01 convert COM output "version" back to caller format 
00:00:04.991026 SQW01 done converting COM output "version" back to caller format 
00:00:04.991026 SQW01 -- leaving __vbox__IVirtualBox_USCOREgetVersion, rc: 0x0 (0) 
00:00:04.992027 SQPmp Request 2 on socket 900 queued for processing (1 items on Q) 
00:00:04.992027 SQW02 New SOAP thread started 
00:00:04.992027 SQW02 Processing connection from IP=127.0.0.1 socket=900 (0 out of 2 threads idle) 
00:00:04.992027 SQW02 -- entering __vbox__IVirtualBox_USCOREgetVersion 
00:00:04.992027 SQW02 ManagedObjectRef::findRefFromId(): looking up objref e3b14703552e6d85-0000000000000002 
00:00:04.992027 SQW02 findComPtrFromId(): returning original IVirtualBox*=0x12855E8 (IUnknown*=0x1292748) 
00:00:04.992027 SQW02 calling COM method COMGETTER(Version) 
00:00:04.993027 SQW02 done calling COM method 
00:00:04.993027 SQW02 convert COM output "version" back to caller format 
00:00:04.993027 SQW02 done converting COM output "version" back to caller format 
00:00:04.993027 SQW02 -- leaving __vbox__IVirtualBox_USCOREgetVersion, rc: 0x0 (0) 
00:00:05.089091 SQW02 -- entering __vbox__IVirtualBox_USCOREfindMachine 
00:00:05.089091 SQW02 ManagedObjectRef::findRefFromId(): looking up objref e3b14703552e6d85-0000000000000002 
00:00:05.089091 SQW02 findComPtrFromId(): returning original IVirtualBox*=0x12855E8 (IUnknown*=0x1292748) 
Thats it. 

Allen Granum 
agranum at leonovus.com 

1309 Carling Avenue 
Ottawa, Ontario, Canada K1Z 7L3 
(613) 722-3232 
x263 

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://www.virtualbox.org/pipermail/vbox-dev/attachments/20131219/b5b5ebd1/attachment-0001.html 
-------------- next part --------------
A non-text attachment was scrubbed...
Name: LeoNovus_Blue_Final_140x67.png
Type: image/png
Size: 7808 bytes
Desc: not available
Url : http://www.virtualbox.org/pipermail/vbox-dev/attachments/20131219/b5b5ebd1/attachment-0001.png 