[libvirt-users] virsh with OSX and virtualbox

Friday, 2 October 2015

I have freshly installed Virtualbox (5.04) and have installed libvirt (1.2.19) using
brew.

When i attempt to run virsh it does not work with the following outputs.

# virsh -c vbox:///session
error: failed to connect to the hypervisor
error: internal error: unable to initialize VirtualBox driver API

Any pointers on what to try next or where to investigate to get more info.

Has anyone got virsh working successfully with OSX and Virtualbox.

I also ran the same command with more logging:

Foyil:~ bengreene$ LIBVIRT_DEBUG=1 virsh -c vbox:///session
2015-10-02 08:52:11.874+0000: 18446744073709551615: info : libvirt version: 1.2.19
2015-10-02 08:52:11.874+0000: 18446744073709551615: debug : virGlobalInit:389 : register
drivers
2015-10-02 08:52:11.874+0000: 18446744073709551615: debug : virRegisterConnectDriver:691 :
driver=0x1007121d8 name=Test
2015-10-02 08:52:11.874+0000: 18446744073709551615: debug : virRegisterConnectDriver:702 :
registering Test as driver 0
2015-10-02 08:52:11.874+0000: 18446744073709551615: debug : virRegisterConnectDriver:691 :
driver=0x100713e00 name=VMWARE
2015-10-02 08:52:11.874+0000: 18446744073709551615: debug : virRegisterConnectDriver:702 :
registering VMWARE as driver 1
2015-10-02 08:52:11.874+0000: 18446744073709551615: debug : virRegisterConnectDriver:691 :
driver=0x1007144f8 name=ESX
2015-10-02 08:52:11.874+0000: 18446744073709551615: debug : virRegisterConnectDriver:702 :
registering ESX as driver 2
2015-10-02 08:52:11.874+0000: 18446744073709551615: debug : virRegisterConnectDriver:691 :
driver=0x100712c10 name=remote
2015-10-02 08:52:11.874+0000: 18446744073709551615: debug : virRegisterConnectDriver:702 :
registering remote as driver 3
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug :
virEventRegisterDefaultImpl:261 : registering default event implementation
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : virEventPollAddHandle:115 :
Used 0 handle slots, adding at least 10 more
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug :
virEventPollInterruptLocked:723 : Skip interrupt, 0 0
2015-10-02 08:52:11.876+0000: 18446744073709551615: info : virEventPollAddHandle:140 :
EVENT_POLL_ADD_HANDLE: watch=1 fd=4 events=1 cb=0x10050c74e opaque=0x0 ff=0x0
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : virEventRegisterImpl:231 :
addHandle=0x10050afa3 updateHandle=0x10050b296 removeHandle=0x10050b3da
addTimeout=0x10050b528 updateTimeout=0x10050b6f6 removeTimeout=0x10050b879
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : virEventPollAddTimeout:230 :
Used 0 timeout slots, adding at least 10 more
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug :
virEventPollInterruptLocked:723 : Skip interrupt, 0 0
2015-10-02 08:52:11.876+0000: 18446744073709551615: info : virEventPollAddTimeout:253 :
EVENT_POLL_ADD_TIMEOUT: timer=1 frequency=-1 cb=0x100490c0c opaque=0x7fff5f774900 ff=0x0
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : virConnectOpenAuth:1339 :
name=vbox:///session, auth=0x100711ff0, flags=0
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : virThreadJobSet:99 : Thread
18446744073709551615 is now running job vshEventLoop
2015-10-02 08:52:11.876+0000: 18446744073709551615: info : virObjectNew:202 : OBJECT_NEW:
obj=0x7f9cda600b10 classname=virConnect
2015-10-02 08:52:11.876+0000: 18446744073709551615: info : virObjectNew:202 : OBJECT_NEW:
obj=0x7f9cda600c20 classname=virConnectCloseCallbackData
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : virEventRunDefaultImpl:305 :
running default event implementation
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug :
virEventPollCleanupTimeouts:526 : Cleanup 1
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : virEventPollCleanupHandles:575
: Cleanup 1
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=4 e=1 d=0
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug :
virEventPollCalculateTimeout:338 : Calculate expiry of 1 timers
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug :
virEventPollCalculateTimeout:371 : No timeout is pending
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : do_open:1132 : name
"vbox:///session" to URI components:
  scheme vbox
  server <null>
  user <null>
  port -1
  path /session

2015-10-02 08:52:11.876+0000: 18446744073709551615: info : virEventPollRunOnce:641 :
EVENT_POLL_RUN: nhandles=1 timeout=-1
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : do_open:1179 : trying driver 0
(Test) ...
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : do_open:1194 : driver 0 Test
returned DECLINED
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : do_open:1179 : trying driver 1
(VMWARE) ...
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : do_open:1194 : driver 1 VMWARE
returned DECLINED
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : do_open:1179 : trying driver 2
(ESX) ...
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : do_open:1194 : driver 2 ESX
returned DECLINED
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : do_open:1179 : trying driver 3
(remote) ...
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : remoteConnectOpen:1176 :
Auto-spawn user daemon instance
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : doRemoteOpen:792 : proceeding
with name = vbox:///session
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : doRemoteOpen:801 : Connecting
with transport 1
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : doRemoteOpen:893 : Proceeding
with sockname /Users/bengreene/.cache/libvirt/libvirt-sock
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : virFileFindResourceFull:1692 :
Resolved 'libvirtd' to '/usr/local/Cellar/libvirt/1.2.19/sbin/libvirtd'
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : virFileMakePathHelper:2571 :
path=/Users/bengreene/.cache/libvirt mode=0700
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : virNetSocketNew:226 :
localAddr=0x7fff5f774330 remoteAddr=0x7fff5f7742a0 fd=7 errfd=-1 pid=0
2015-10-02 08:52:11.876+0000: 18446744073709551615: info : virObjectNew:202 : OBJECT_NEW:
obj=0x7f9cda700730 classname=virNetSocket
2015-10-02 08:52:11.876+0000: 18446744073709551615: info : virNetSocketNew:277 :
RPC_SOCKET_NEW: sock=0x7f9cda700730 fd=7 errfd=-1 pid=0 localAddr=127.0.0.1;0,
remoteAddr=127.0.0.1;0
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : virFileClose:103 : Closed fd
6
2015-10-02 08:52:11.876+0000: 18446744073709551615: info : virObjectNew:202 : OBJECT_NEW:
obj=0x7f9cda7005c0 classname=virNetClient
2015-10-02 08:52:11.876+0000: 18446744073709551615: info : virNetClientNew:327 :
RPC_CLIENT_NEW: client=0x7f9cda7005c0 sock=0x7f9cda700730
2015-10-02 08:52:11.876+0000: 18446744073709551615: info : virObjectRef:296 : OBJECT_REF:
obj=0x7f9cda7005c0
2015-10-02 08:52:11.876+0000: 18446744073709551615: info : virObjectRef:296 : OBJECT_REF:
obj=0x7f9cda700730
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug :
virEventPollInterruptLocked:727 : Interrupting
2015-10-02 08:52:11.876+0000: 18446744073709551615: info : virEventPollAddHandle:140 :
EVENT_POLL_ADD_HANDLE: watch=2 fd=7 events=1 cb=0x10062471b opaque=0x7f9cda700730
ff=0x100624768
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : virKeepAliveNew:199 :
client=0x7f9cda7005c0, interval=-1, count=0
2015-10-02 08:52:11.876+0000: 18446744073709551615: info : virObjectNew:202 : OBJECT_NEW:
obj=0x7f9cda700910 classname=virKeepAlive
2015-10-02 08:52:11.876+0000: 18446744073709551615: debug : virEventPollRunOnce:651 : Poll
got 1 event(s)
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virKeepAliveNew:218 :
RPC_KEEPALIVE_NEW: ka=0x7f9cda700910 client=0x7f9cda7005c0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollDispatchTimeouts:433 : Dispatch 1
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virObjectRef:296 : OBJECT_REF:
obj=0x7f9cda7005c0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:479 : Dispatch 1
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virObjectRef:296 : OBJECT_REF:
obj=0x7f9cda600c20
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:493 : i=0 w=1
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virObjectNew:202 : OBJECT_NEW:
obj=0x7f9cda600ed0 classname=virNetClientProgram
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virEventPollDispatchHandles:507
: EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virObjectNew:202 : OBJECT_NEW:
obj=0x7f9cda600e00 classname=virNetClientProgram
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virObjectNew:202 : OBJECT_NEW:
obj=0x7f9cda600e30 classname=virNetClientProgram
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollCleanupTimeouts:526 : Cleanup 1
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virObjectRef:296 : OBJECT_REF:
obj=0x7f9cda600ed0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventPollCleanupHandles:575
: Cleanup 2
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virObjectRef:296 : OBJECT_REF:
obj=0x7f9cda600e00
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventRunDefaultImpl:305 :
running default event implementation
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virObjectRef:296 : OBJECT_REF:
obj=0x7f9cda600e30
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollCleanupTimeouts:526 : Cleanup 1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : doRemoteOpen:1010 : Trying
authentication
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventPollCleanupHandles:575
: Cleanup 2
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=4 e=1 d=0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virNetMessageNew:46 :
msg=0x7f9cda600d10 tracked=0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollCalculateTimeout:338 : Calculate expiry of 1 timers
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollCalculateTimeout:371 : No timeout is pending
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virEventPollRunOnce:641 :
EVENT_POLL_RUN: nhandles=2 timeout=-1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virNetMessageEncodePayload:376
: Encode length as 28
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virNetClientSendInternal:1950 :
RPC_CLIENT_MSG_TX_QUEUE: client=0x7f9cda7005c0 len=28 prog=536903814 vers=1 proc=66 type=0
status=0 serial=0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virNetClientCallNew:1903 : New
call 0x7f9cda600f00: msg=0x7f9cda600d10, expectReply=1, nonBlock=0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virNetClientIO:1712 : Outgoing
message prog=536903814 version=1 serial=0 proc=66 type=0 length=28 dispatch=0x0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virNetClientIO:1771 : We have
the buck head=0x7f9cda600f00 call=0x7f9cda600f00
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollInterruptLocked:727 : Interrupting
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventPollRunOnce:651 : Poll
got 1 event(s)
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollDispatchTimeouts:433 : Dispatch 1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:479 : Dispatch 2
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:493 : i=0 w=1
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virEventPollDispatchHandles:507
: EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollCleanupTimeouts:526 : Cleanup 1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventPollCleanupHandles:575
: Cleanup 2
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventRunDefaultImpl:305 :
running default event implementation
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollCleanupTimeouts:526 : Cleanup 1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventPollCleanupHandles:575
: Cleanup 2
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=4 e=1 d=0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=0 d=0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollCalculateTimeout:338 : Calculate expiry of 1 timers
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollCalculateTimeout:371 : No timeout is pending
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virEventPollRunOnce:641 :
EVENT_POLL_RUN: nhandles=1 timeout=-1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virNetMessageDecodeLength:151
: Got length, now need 36 total (32 more)
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virNetClientCallDispatch:1122 :
RPC_CLIENT_MSG_RX: client=0x7f9cda7005c0 len=36 prog=536903814 vers=1 proc=66 type=1
status=0 serial=0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virKeepAliveCheckMessage:377 :
ka=0x7f9cda700910, client=0x7f9cda7005c0, msg=0x7f9cda700640
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virNetMessageClear:57 :
msg=0x7f9cda700640 nfds=0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virNetClientIOEventLoopPassTheBuck:1419 : Giving up the buck 0x7f9cda600f00
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virNetClientIOEventLoopPassTheBuck:1433 : No thread to pass the buck to
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollInterruptLocked:727 : Interrupting
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virNetClientIO:1801 : All done
with our call head=0x0 call=0x7f9cda600f00 rv=0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventPollRunOnce:651 : Poll
got 1 event(s)
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollDispatchTimeouts:433 : Dispatch 1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:479 : Dispatch 1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virNetMessageFree:74 :
msg=0x7f9cda600d10 nfds=0 cb=0x0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:493 : i=0 w=1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virNetMessageNew:46 :
msg=0x7f9cda500170 tracked=0
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virEventPollDispatchHandles:507
: EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollCleanupTimeouts:526 : Cleanup 1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virNetMessageEncodePayload:376
: Encode length as 32
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventPollCleanupHandles:575
: Cleanup 2
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virNetClientSendInternal:1950 :
RPC_CLIENT_MSG_TX_QUEUE: client=0x7f9cda7005c0 len=32 prog=536903814 vers=1 proc=60 type=0
status=0 serial=1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventRunDefaultImpl:305 :
running default event implementation
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virNetClientCallNew:1903 : New
call 0x7f9cda500260: msg=0x7f9cda500170, expectReply=1, nonBlock=0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollCleanupTimeouts:526 : Cleanup 1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virNetClientIO:1712 : Outgoing
message prog=536903814 version=1 serial=1 proc=60 type=0 length=32 dispatch=0x0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventPollCleanupHandles:575
: Cleanup 2
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virNetClientIO:1771 : We have
the buck head=0x7f9cda500260 call=0x7f9cda500260
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=4 e=1 d=0
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollCalculateTimeout:338 : Calculate expiry of 1 timers
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollCalculateTimeout:371 : No timeout is pending
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virEventPollRunOnce:641 :
EVENT_POLL_RUN: nhandles=2 timeout=-1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollInterruptLocked:727 : Interrupting
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventPollRunOnce:651 : Poll
got 1 event(s)
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollDispatchTimeouts:433 : Dispatch 1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:479 : Dispatch 2
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:493 : i=0 w=1
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virEventPollDispatchHandles:507
: EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollCleanupTimeouts:526 : Cleanup 1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventPollCleanupHandles:575
: Cleanup 2
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventRunDefaultImpl:305 :
running default event implementation
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollCleanupTimeouts:526 : Cleanup 1
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventPollCleanupHandles:575
: Cleanup 2
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=4 e=1 d=0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=0 d=0
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollCalculateTimeout:338 : Calculate expiry of 1 timers
2015-10-02 08:52:11.877+0000: 18446744073709551615: debug :
virEventPollCalculateTimeout:371 : No timeout is pending
2015-10-02 08:52:11.877+0000: 18446744073709551615: info : virEventPollRunOnce:641 :
EVENT_POLL_RUN: nhandles=1 timeout=-1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virNetMessageDecodeLength:151
: Got length, now need 32 total (28 more)
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virNetClientCallDispatch:1122 :
RPC_CLIENT_MSG_RX: client=0x7f9cda7005c0 len=32 prog=536903814 vers=1 proc=60 type=1
status=0 serial=1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virKeepAliveCheckMessage:377 :
ka=0x7f9cda700910, client=0x7f9cda7005c0, msg=0x7f9cda700640
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virNetMessageClear:57 :
msg=0x7f9cda700640 nfds=0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virNetClientIOEventLoopPassTheBuck:1419 : Giving up the buck 0x7f9cda500260
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virNetClientIOEventLoopPassTheBuck:1433 : No thread to pass the buck to
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollInterruptLocked:727 : Interrupting
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virNetClientIO:1801 : All done
with our call head=0x0 call=0x7f9cda500260 rv=0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virNetMessageFree:74 :
msg=0x7f9cda500170 nfds=0 cb=0x0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : doRemoteOpen:1036 : Trying to
open URI vbox:///session
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventPollRunOnce:651 : Poll
got 1 event(s)
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virNetMessageNew:46 :
msg=0x7f9cda500150 tracked=0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollDispatchTimeouts:433 : Dispatch 1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:479 : Dispatch 1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virNetMessageEncodePayload:376
: Encode length as 56
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:493 : i=0 w=1
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virNetClientSendInternal:1950 :
RPC_CLIENT_MSG_TX_QUEUE: client=0x7f9cda7005c0 len=56 prog=536903814 vers=1 proc=1 type=0
status=0 serial=2
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virEventPollDispatchHandles:507
: EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virNetClientCallNew:1903 : New
call 0x7f9cda700440: msg=0x7f9cda500150, expectReply=1, nonBlock=0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollCleanupTimeouts:526 : Cleanup 1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virNetClientIO:1712 : Outgoing
message prog=536903814 version=1 serial=2 proc=1 type=0 length=56 dispatch=0x0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventPollCleanupHandles:575
: Cleanup 2
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virNetClientIO:1771 : We have
the buck head=0x7f9cda700440 call=0x7f9cda700440
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventRunDefaultImpl:305 :
running default event implementation
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollCleanupTimeouts:526 : Cleanup 1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventPollCleanupHandles:575
: Cleanup 2
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=4 e=1 d=0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollCalculateTimeout:338 : Calculate expiry of 1 timers
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollCalculateTimeout:371 : No timeout is pending
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virEventPollRunOnce:641 :
EVENT_POLL_RUN: nhandles=2 timeout=-1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollInterruptLocked:727 : Interrupting
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventPollRunOnce:651 : Poll
got 1 event(s)
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollDispatchTimeouts:433 : Dispatch 1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:479 : Dispatch 2
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:493 : i=0 w=1
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virEventPollDispatchHandles:507
: EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollCleanupTimeouts:526 : Cleanup 1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventPollCleanupHandles:575
: Cleanup 2
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventRunDefaultImpl:305 :
running default event implementation
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollCleanupTimeouts:526 : Cleanup 1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventPollCleanupHandles:575
: Cleanup 2
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=4 e=1 d=0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=0 d=0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollCalculateTimeout:338 : Calculate expiry of 1 timers
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollCalculateTimeout:371 : No timeout is pending
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virEventPollRunOnce:641 :
EVENT_POLL_RUN: nhandles=1 timeout=-1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virNetMessageDecodeLength:151
: Got length, now need 208 total (204 more)
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virNetClientCallDispatch:1122 :
RPC_CLIENT_MSG_RX: client=0x7f9cda7005c0 len=208 prog=536903814 vers=1 proc=1 type=1
status=1 serial=2
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virKeepAliveCheckMessage:377 :
ka=0x7f9cda700910, client=0x7f9cda7005c0, msg=0x7f9cda700640
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virNetMessageClear:57 :
msg=0x7f9cda700640 nfds=0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virNetClientIOEventLoopPassTheBuck:1419 : Giving up the buck 0x7f9cda700440
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virNetClientIOEventLoopPassTheBuck:1433 : No thread to pass the buck to
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollInterruptLocked:727 : Interrupting
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virNetClientIO:1801 : All done
with our call head=0x0 call=0x7f9cda700440 rv=0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventPollRunOnce:651 : Poll
got 1 event(s)
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollDispatchTimeouts:433 : Dispatch 1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virNetMessageFree:74 :
msg=0x7f9cda500150 nfds=0 cb=0x0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:479 : Dispatch 1
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virObjectUnref:259 :
OBJECT_UNREF: obj=0x7f9cda600ed0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:493 : i=0 w=1
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virObjectUnref:259 :
OBJECT_UNREF: obj=0x7f9cda600e00
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virEventPollDispatchHandles:507
: EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virObjectUnref:259 :
OBJECT_UNREF: obj=0x7f9cda600e30
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollCleanupTimeouts:526 : Cleanup 1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virNetClientCloseInternal:695
: client=0x7f9cda7005c0 wantclose=0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventPollCleanupHandles:575
: Cleanup 2
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virNetClientMarkClose:638 :
client=0x7f9cda7005c0, reason=3
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventRunDefaultImpl:305 :
running default event implementation
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virEventPollRemoveHandle:186 :
EVENT_POLL_REMOVE_HANDLE: watch=2
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollCleanupTimeouts:526 : Cleanup 1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventPollCleanupHandles:575
: Cleanup 2
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=4 e=1 d=0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollCalculateTimeout:338 : Calculate expiry of 1 timers
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollCalculateTimeout:371 : No timeout is pending
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virEventPollRunOnce:641 :
EVENT_POLL_RUN: nhandles=2 timeout=-1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventPollRemoveHandle:199 :
mark delete 1 7
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollInterruptLocked:727 : Interrupting
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virNetClientIOEventLoopPassTheBuck:1419 : Giving up the buck 0x0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventPollRunOnce:651 : Poll
got 1 event(s)
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virNetClientIOEventLoopPassTheBuck:1433 : No thread to pass the buck to
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollDispatchTimeouts:433 : Dispatch 1
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virNetClientCloseLocked:654 :
client=0x7f9cda7005c0, sock=0x7f9cda700730, reason=3
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:479 : Dispatch 2
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virObjectUnref:259 :
OBJECT_UNREF: obj=0x7f9cda700730
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:493 : i=0 w=1
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virObjectRef:296 : OBJECT_REF:
obj=0x7f9cda7005c0
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virEventPollDispatchHandles:507
: EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virKeepAliveStop:310 :
RPC_KEEPALIVE_STOP: ka=0x7f9cda700910 client=0x7f9cda7005c0
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:493 : i=1 w=2
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virObjectUnref:259 :
OBJECT_UNREF: obj=0x7f9cda700910
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:496 : Skip deleted n=1 w=2 f=7
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virObjectUnref:261 :
OBJECT_DISPOSE: obj=0x7f9cda700910
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug :
virEventPollCleanupTimeouts:526 : Cleanup 1
2015-10-02 08:52:11.878+0000: 18446744073709551615: info : virKeepAliveDispose:230 :
RPC_KEEPALIVE_DISPOSE: ka=0x7f9cda700910
2015-10-02 08:52:11.878+0000: 18446744073709551615: debug : virEventPollCleanupHandles:575
: Cleanup 2
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virObjectUnref:259 :
OBJECT_UNREF: obj=0x7f9cda7005c0
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virEventPollCleanupHandles:588
: EVENT_POLL_PURGE_HANDLE: watch=2
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virObjectUnref:259 :
OBJECT_UNREF: obj=0x7f9cda7005c0
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virObjectUnref:259 :
OBJECT_UNREF: obj=0x7f9cda700730
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virObjectUnref:259 :
OBJECT_UNREF: obj=0x7f9cda7005c0
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virObjectUnref:261 :
OBJECT_DISPOSE: obj=0x7f9cda700730
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virObjectUnref:259 :
OBJECT_UNREF: obj=0x7f9cda7005c0
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virNetSocketDispose:1157 :
RPC_SOCKET_DISPOSE: sock=0x7f9cda700730
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virObjectUnref:261 :
OBJECT_DISPOSE: obj=0x7f9cda7005c0
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virNetClientDispose:606 :
RPC_CLIENT_DISPOSE: client=0x7f9cda7005c0
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virObjectUnref:259 :
OBJECT_UNREF: obj=0x7f9cda600c20
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virObjectUnref:259 :
OBJECT_UNREF: obj=0x7f9cda600ed0
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virObjectUnref:261 :
OBJECT_DISPOSE: obj=0x7f9cda600ed0
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virObjectUnref:259 :
OBJECT_UNREF: obj=0x7f9cda600e00
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virObjectUnref:261 :
OBJECT_DISPOSE: obj=0x7f9cda600e00
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virObjectUnref:259 :
OBJECT_UNREF: obj=0x7f9cda600e30
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virObjectUnref:261 :
OBJECT_DISPOSE: obj=0x7f9cda600e30
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug : virFileClose:103 : Closed fd
8
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug : virFileClose:103 : Closed fd
6
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug : virNetMessageClear:57 :
msg=0x7f9cda700640 nfds=0
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug : do_open:1194 : driver 3 remote
returned ERROR
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virObjectUnref:259 :
OBJECT_UNREF: obj=0x7f9cda600b10
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug : virFileClose:103 : Closed fd
7
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virObjectUnref:261 :
OBJECT_DISPOSE: obj=0x7f9cda600b10
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug : virEventRunDefaultImpl:305 :
running default event implementation
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virObjectUnref:259 :
OBJECT_UNREF: obj=0x7f9cda600c20
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug :
virEventPollCleanupTimeouts:526 : Cleanup 1
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virObjectUnref:261 :
OBJECT_DISPOSE: obj=0x7f9cda600c20
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug : virEventPollCleanupHandles:575
: Cleanup 1
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=4 e=1 d=0
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug :
virEventPollCalculateTimeout:338 : Calculate expiry of 1 timers
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug :
virEventPollCalculateTimeout:371 : No timeout is pending
error: 2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virEventPollRunOnce:641
: EVENT_POLL_RUN: nhandles=1 timeout=-1
failed to connect to the hypervisor
error: internal error: unable to initialize VirtualBox driver API
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug : virFileMakePathHelper:2571 :
path=/Users/bengreene/.cache/libvirt/virsh mode=0755
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug :
virEventPollInterruptLocked:727 : Interrupting
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virEventPollAddTimeout:253 :
EVENT_POLL_ADD_TIMEOUT: timer=2 frequency=0 cb=0x100493620 opaque=0x0 ff=0x0
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug : virEventPollRunOnce:651 : Poll
got 1 event(s)
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug :
virEventPollDispatchTimeouts:433 : Dispatch 2
2015-10-02 08:52:11.879+0000: 18446744073709551615: info :
virEventPollDispatchTimeouts:456 : EVENT_POLL_DISPATCH_TIMEOUT: timer=2
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:479 : Dispatch 1
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug :
virEventPollDispatchHandles:493 : i=0 w=1
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virEventPollDispatchHandles:507
: EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug :
virEventPollCleanupTimeouts:526 : Cleanup 2
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug : virEventPollCleanupHandles:575
: Cleanup 1
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug : virThreadJobClear:124 : Thread
18446744073709551615 finished job vshEventLoop with ret=0
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virEventPollRemoveTimeout:305 :
EVENT_POLL_REMOVE_TIMEOUT: timer=2
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug :
virEventPollInterruptLocked:723 : Skip interrupt, 0 123145302839296
2015-10-02 08:52:11.879+0000: 18446744073709551615: info : virEventPollRemoveTimeout:305 :
EVENT_POLL_REMOVE_TIMEOUT: timer=1
2015-10-02 08:52:11.879+0000: 18446744073709551615: debug :
virEventPollInterruptLocked:723 : Skip interrupt, 0 123145302839296
Foyil:~ bengreene$

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010