[Xen-API] ffsSR - xvda disk not visible

[Dawid Kowalski <dkadds2@xxxxxxxxx>]

Hi Guys,

Which drivers on guest side are required to use FFS with qcow2 SR?
ubuntu 14.04.1 ISO after booting does not discover xvda.

Is there any specific driver which is required? Or maybe something is 
configured incorrectly on my side?
### log - starting VM
Feb 16 00:50:10 silver xenopsd-xc: [debug|silver|9|events|task_server] 
Task 615 failed; exception = ["Does_not_exist", ["VM", 
"4f1cbed7-eba5-4591-bc12-313612a9ecfe\/vbd.xvdb"]]
Feb 16 00:50:10 silver xenopsd-xc: [debug|silver|9|events|task_server]
Feb 16 00:50:10 silver xenopsd-xc: [debug|silver|3|events|xenops_server] 
Received an event on managed VBD 4f1cbed7-eba5-4591-bc12-313612a9ecfe.xvdb
Feb 16 00:50:10 silver xenopsd-xc: [debug|silver|3|queue|xenops_server] 
Queue.push ["VBD_check_state", ["4f1cbed7-eba5-4591-bc12-313612a9ecfe", 
"xvdb"]] onto redirected 4f1cbed7-eba5-4591-bc12-313612a9ecfe:[ 
["VBD_check_state", ["4f1cbed7-eba5-4591-bc12-313612a9ecfe", "xvdb"]] ]
Feb 16 00:50:10 silver xapi: [debug|silver|12895||storage_impl] 
dbg:dp_destroy dp:xenopsd/task/830 
sr:0e141376-6525-ff18-ffee-862446f5a617 
vdi:ubuntu-14.04.1-server-amd64.iso superstate:attached  RO
Feb 16 00:50:10 silver xenopsd-xc: [debug|silver|9||xenops_server] 
TASK.signal 615 (object deleted)
Feb 16 00:50:10 silver xenopsd-xc: [debug|silver|11||xenops_server] 
Queue.pop returned ["VBD_check_state", 
["4f1cbed7-eba5-4591-bc12-313612a9ecfe", "xvdb"]]
Feb 16 00:50:10 silver xenopsd-xc: 
[debug|silver|11|events|xenops_server] Task 616 reference events: 
["VBD_check_state", ["4f1cbed7-eba5-4591-bc12-313612a9ecfe", "xvdb"]]
Feb 16 00:50:10 silver xenopsd-xc: 
[debug|silver|11|events|xenops_server] VBD.check_state 
4f1cbed7-eba5-4591-bc12-313612a9ecfe.xvdb
Feb 16 00:50:10 silver xenopsd-xc: [ 
info|silver|11|events|xenops_server] Caught 
Xenops_interface.Does_not_exist(_) executing ["VBD_check_state", 
["4f1cbed7-eba5-4591-bc12-313612a9ecfe", "xvdb"]]: triggering cleanup 
actions
Feb 16 00:50:10 silver xenopsd-xc: [debug|silver|11|events|task_server] 
Task 616 failed; exception = ["Does_not_exist", ["VM", 
"4f1cbed7-eba5-4591-bc12-313612a9ecfe\/vbd.xvdb"]]
Feb 16 00:50:10 silver xenopsd-xc: [debug|silver|11|events|task_server]
Feb 16 00:50:10 silver xenopsd-xc: [debug|silver|11||xenops_server] 
TASK.signal 616 (object deleted)
Feb 16 00:50:10 silver xapi: [debug|silver|12897||dummytaskhelper] task 
VDI.detach D:7c1380eb5d9a created by task dp_destroy
Feb 16 00:50:10 silver xapi: [debug|silver|12897|VDI.detach 
D:7c1380eb5d9a|sm] SM iso vdi_detach 
sr=OpaqueRef:202bd8e5-96ab-a7b7-5859-e39088f07896 
vdi=OpaqueRef:dcbf7bbe-630a-57a3-2dd3-13dc63840151
Feb 16 00:50:10 silver xapi: [ info|silver|12897|sm_exec 
D:3af3ae2ca896|xapi] Session.create 
trackid=5bcc3ca693f10936a607d485e8a5754c pool=false uname= originator= 
is_local_superuser=true auth_user_sid= 
parent=trackid=9834f5af41c964e225f24279aefe4e49
Feb 16 00:50:10 silver xapi: [debug|silver|12897|sm_exec 
D:3af3ae2ca896|mscgen] xapi=>xapi [label="session.get_uuid"];
Feb 16 00:50:10 silver xapi: [debug|silver|12898 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.get_uuid 
D:1139e18d7e52 created by task D:3af3ae2ca896
Feb 16 00:50:10 silver xapi: [debug|silver|12897|sm_exec 
D:3af3ae2ca896|mscgen] smapiv2=>smapiv1 [label="vdi_detach"];
Feb 16 00:50:10 silver logger: /etc/xen/scripts/block: remove 
XENBUS_PATH=backend/vbd/0/51728
Feb 16 00:50:10 silver logger: /etc/xen/scripts/xen-hotplug-cleanup: 
XENBUS_PATH=backend/vbd/0/51728
Feb 16 00:50:10 silver xapi: [debug|silver|12899 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config 
D:152b792edd11 created by task D:7c1380eb5d9a
Feb 16 00:50:10 silver SM: [31206] vdi_detach {'sr_uuid': 
'0e141376-6525-ff18-ffee-862446f5a617', 'subtask_of': 
'DummyRef:|7c1380eb-5d9a-c1f5-662d-a2b76a37d321|VDI.detach', 'vdi_ref': 
'OpaqueRef:dcbf7bbe-630a-57a3-2dd3-13dc63840151', 'vdi_on_boot': 
'persist', 'args': [], 'vdi_location': 
'ubuntu-14.04.1-server-amd64.iso', 'host_ref': 
'OpaqueRef:0d0d7bf7-4d03-afc4-4280-8724014224ba', 'session_ref': 
'OpaqueRef:2937fb1b-bd5b-8892-85dc-a286dda1c07e', 'device_config': 
{'path': '/mnt/images/ISOs', 'legacy_mode': 'true', 'SRmaster': 'true', 
'location': '/mnt/images/ISOs'}, 'command': 'vdi_detach', 
'vdi_allow_caching': 'false', 'sr_ref': 
'OpaqueRef:202bd8e5-96ab-a7b7-5859-e39088f07896', 'vdi_uuid': 
'29327dc0-7397-4906-bcc9-1868a001a55c'}
Feb 16 00:50:10 silver SM: [31206] lock: opening lock file 
/var/lock/sm/29327dc0-7397-4906-bcc9-1868a001a55c/vdi
Feb 16 00:50:10 silver SM: [31206] Deactivate & detach
Feb 16 00:50:10 silver SM: [31206] ['/usr/lib/blktap/sbin/tap-ctl', 
'close', '-p', '31098', '-m', '0']
Feb 16 00:50:10 silver tapdisk[31098]: received 'close' message (uuid = 0)
Feb 16 00:50:10 silver tapdisk[31098]: nbd: NBD server pause(0x2245180)
Feb 16 00:50:10 silver tapdisk[31098]: nbd: NBD server free(0x2245180)
Feb 16 00:50:10 silver tapdisk[31098]: closed image 
/mnt/images/ISOs/ubuntu-14.04.1-server-amd64.iso (0 users, state: 
0x00000002, type: 0)
Feb 16 00:50:10 silver tapdisk[31098]: sending 'close response' message 
(uuid = 0)
Feb 16 00:50:10 silver SM: [31206]  = 0
Feb 16 00:50:10 silver SM: [31206] Attempt to deregister tapdisk with RRDD.
Feb 16 00:50:10 silver SM: [31206] ERROR: Failed to deregister tapdisk 
with RRDD due to [Errno 2] No such file or directory
Feb 16 00:50:10 silver SM: [31206] ['/usr/lib/blktap/sbin/tap-ctl', 
'detach', '-p', '31098', '-m', '0']
Feb 16 00:50:10 silver tapdisk[31098]: received 'detach' message (uuid = 0)
Feb 16 00:50:10 silver tapdisk[31098]: sending 'detach response' message 
(uuid = 0)
Feb 16 00:50:10 silver tapdisk[31098]: tapdisk-log: closing after 0 errors
Feb 16 00:50:10 silver tapdisk[31098]: tapdisk-syslog: 18 messages, 1540 
bytes, xmits: 19, failed: 0, dropped: 0
Feb 16 00:50:10 silver tapdisk[31098]: tapdisk-control: draining 1 
connections
Feb 16 00:50:10 silver tapdisk[31098]: tapdisk-control: done
Feb 16 00:50:10 silver SM: [31206]  = 0
Feb 16 00:50:10 silver SM: [31206] ['/usr/lib/blktap/sbin/tap-ctl', 
'free', '-m', '0']
Feb 16 00:50:10 silver SM: [31206]  = 0
Feb 16 00:50:10 silver SM: [31206] tap.deactivate: Shut down 
Tapdisk(aio:/mnt/images/ISOs/ubuntu-14.04.1-server-amd64.iso, pid=31098, 
minor=0, state=R)
Feb 16 00:50:10 silver xapi: [debug|silver|12900 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_by_uuid 
D:0b62da4cad4f created by task D:7c1380eb5d9a
Feb 16 00:50:10 silver xapi: [debug|silver|12901 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_SR 
D:22efefdf803d created by task D:7c1380eb5d9a
Feb 16 00:50:10 silver xapi: [debug|silver|12902 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_uuid 
D:3cfc187d57a4 created by task D:7c1380eb5d9a
Feb 16 00:50:10 silver xapi: [debug|silver|12903 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid 
D:d7f6f3954891 created by task D:7c1380eb5d9a
Feb 16 00:50:10 silver xapi: [debug|silver|12904 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_type 
D:868bef4268a5 created by task D:7c1380eb5d9a
Feb 16 00:50:10 silver xapi: [debug|silver|12905 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task 
dispatch:SM.get_all_records_where D:64275e66bf01 created by task 
D:7c1380eb5d9a
Feb 16 00:50:10 silver xapi: [debug|silver|12906 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:SM.get_driver_filename 
D:3154e10efeeb created by task D:7c1380eb5d9a
Feb 16 00:50:10 silver xapi: [debug|silver|12907 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task 
dispatch:VM.get_all_records_where D:714c39e82da1 created by task 
D:7c1380eb5d9a
Feb 16 00:50:10 silver xapi: [debug|silver|12908 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task 
dispatch:PBD.get_all_records_where D:60b41abaa24b created by task 
D:7c1380eb5d9a
Feb 16 00:50:10 silver xapi: [debug|silver|12909 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:PBD.get_device_config 
D:945f1735bd82 created by task D:7c1380eb5d9a
Feb 16 00:50:10 silver SM: [31206] lock: closed 
/var/lock/sm/29327dc0-7397-4906-bcc9-1868a001a55c/vdi
Feb 16 00:50:10 silver xapi: [ info|silver|12897|sm_exec 
D:3af3ae2ca896|xapi] Session.destroy 
trackid=5bcc3ca693f10936a607d485e8a5754c
Feb 16 00:50:10 silver xapi: [debug|silver|12895||storage_impl] 
dbg:dp_destroy dp:xenopsd/task/830 
sr:0e141376-6525-ff18-ffee-862446f5a617 
vdi:ubuntu-14.04.1-server-amd64.iso superstate:detached
Feb 16 00:50:10 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_utils] TypedTable: Writing 
extra/346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:10 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops] VBD.pre_plug
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|xenops] Processing disk 
SR=13d626f8-4a8b-e822-f821-de35f23d2886 VDI=manual
Feb 16 00:50:10 silver xapi: [ info|silver|12913||storage_impl] 
VDI.attach dbg:attach_and_activate 
dp:vbd/346f48e4-5d8c-1d72-487a-c33565175be7/xvda 
sr:13d626f8-4a8b-e822-f821-de35f23d2886 vdi:manual read_write:true
Feb 16 00:50:10 silver xapi: [debug|silver|12913||storage_impl] 
dbg:attach_and_activate dp:vbd/346f48e4-5d8c-1d72-487a-c33565175be7/xvda 
sr:13d626f8-4a8b-e822-f821-de35f23d2886 vdi:manual superstate:attached  RW
Feb 16 00:50:10 silver xapi: [ info|silver|12914||storage_impl] 
VDI.activate dbg:attach_and_activate 
dp:vbd/346f48e4-5d8c-1d72-487a-c33565175be7/xvda 
sr:13d626f8-4a8b-e822-f821-de35f23d2886 vdi:manual
Feb 16 00:50:10 silver xapi: [debug|silver|12914||storage_impl] 
dbg:attach_and_activate dp:vbd/346f48e4-5d8c-1d72-487a-c33565175be7/xvda 
sr:13d626f8-4a8b-e822-f821-de35f23d2886 vdi:manual superstate:activated RW
Feb 16 00:50:10 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops] VBD.pre_plug
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|xenops] Processing disk 
SR=0e141376-6525-ff18-ffee-862446f5a617 VDI=ubuntu-14.04.1-server-amd64.iso
Feb 16 00:50:10 silver xapi: [ info|silver|12916||storage_impl] 
VDI.attach dbg:attach_and_activate 
dp:vbd/346f48e4-5d8c-1d72-487a-c33565175be7/xvdb 
sr:0e141376-6525-ff18-ffee-862446f5a617 
vdi:ubuntu-14.04.1-server-amd64.iso read_write:false
Feb 16 00:50:10 silver xapi: [debug|silver|12917||dummytaskhelper] task 
VDI.attach D:8c406715ea26 created by task attach_and_activate
Feb 16 00:50:10 silver xapi: [debug|silver|12917|VDI.attach 
D:8c406715ea26|sm] SM iso vdi_attach 
sr=OpaqueRef:202bd8e5-96ab-a7b7-5859-e39088f07896 
vdi=OpaqueRef:dcbf7bbe-630a-57a3-2dd3-13dc63840151 writable=false
Feb 16 00:50:10 silver xapi: [ info|silver|12917|sm_exec 
D:c9323ac816a3|xapi] Session.create 
trackid=b22128e9d207c07e523281a816915b9e pool=false uname= originator= 
is_local_superuser=true auth_user_sid= 
parent=trackid=9834f5af41c964e225f24279aefe4e49
Feb 16 00:50:10 silver xapi: [debug|silver|12917|sm_exec 
D:c9323ac816a3|mscgen] xapi=>xapi [label="session.get_uuid"];
Feb 16 00:50:10 silver xapi: [debug|silver|12918 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.get_uuid 
D:0de0b3b9c003 created by task D:c9323ac816a3
Feb 16 00:50:10 silver xapi: [debug|silver|12917|sm_exec 
D:c9323ac816a3|mscgen] smapiv2=>smapiv1 [label="vdi_attach"];
Feb 16 00:50:10 silver xapi: [debug|silver|12919 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config 
D:5f8597ff84a1 created by task D:8c406715ea26
Feb 16 00:50:10 silver SM: [31267] vdi_attach {'sr_uuid': 
'0e141376-6525-ff18-ffee-862446f5a617', 'subtask_of': 
'DummyRef:|8c406715-ea26-eada-26b2-edc7dd336a00|VDI.attach', 'vdi_ref': 
'OpaqueRef:dcbf7bbe-630a-57a3-2dd3-13dc63840151', 'vdi_on_boot': 
'persist', 'args': ['false'], 'vdi_location': 
'ubuntu-14.04.1-server-amd64.iso', 'host_ref': 
'OpaqueRef:0d0d7bf7-4d03-afc4-4280-8724014224ba', 'session_ref': 
'OpaqueRef:616117d8-104a-785c-876f-bc6cf3eec282', 'device_config': 
{'path': '/mnt/images/ISOs', 'legacy_mode': 'true', 'SRmaster': 'true', 
'location': '/mnt/images/ISOs'}, 'command': 'vdi_attach', 
'vdi_allow_caching': 'false', 'sr_ref': 
'OpaqueRef:202bd8e5-96ab-a7b7-5859-e39088f07896', 'vdi_uuid': 
'29327dc0-7397-4906-bcc9-1868a001a55c'}
Feb 16 00:50:10 silver SM: [31267] lock: opening lock file 
/var/lock/sm/29327dc0-7397-4906-bcc9-1868a001a55c/vdi
Feb 16 00:50:10 silver xapi: [ info|silver|12920 UNIX 
/var/lib/xcp/xapi|session.login_with_password D:97adff20c142|xapi] 
Session.create trackid=57b994bfa3775d79af667c037eb2e145 pool=false 
uname=root originator= is_local_superuser=true auth_user_sid= 
parent=trackid=9834f5af41c964e225f24279aefe4e49
Feb 16 00:50:10 silver xapi: [debug|silver|12920 UNIX 
/var/lib/xcp/xapi|session.login_with_password D:97adff20c142|mscgen] 
xapi=>xapi [label="session.get_uuid"];
Feb 16 00:50:10 silver xapi: [debug|silver|12921 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.get_uuid 
D:bdf1bed09187 created by task D:97adff20c142
Feb 16 00:50:10 silver xapi: [ info|silver|12928 UNIX 
/var/lib/xcp/xapi|session.logout D:8e2ad99c94d7|xapi] Session.destroy 
trackid=57b994bfa3775d79af667c037eb2e145
Feb 16 00:50:10 silver SM: [31267] Attach & activate
Feb 16 00:50:10 silver SM: [31267] 
PhyLink(/dev/sm/phy/0e141376-6525-ff18-ffee-862446f5a617/29327dc0-7397-4906-bcc9-1868a001a55c) 
-> /mnt/images/ISOs/ubuntu-14.04.1-server-amd64.iso
Feb 16 00:50:10 silver xapi: [debug|silver|12929 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all_records 
D:68468763bbdd created by task D:8c406715ea26
Feb 16 00:50:10 silver xapi: [ info|silver|12930 UNIX 
/var/lib/xcp/xapi|session.login_with_password D:4f2a236c3d51|xapi] 
Session.create trackid=a4ad8fb26ffc6e4394f0453c9f565ac6 pool=false 
uname=root originator= is_local_superuser=true auth_user_sid= 
parent=trackid=9834f5af41c964e225f24279aefe4e49
Feb 16 00:50:10 silver xapi: [debug|silver|12930 UNIX 
/var/lib/xcp/xapi|session.login_with_password D:4f2a236c3d51|mscgen] 
xapi=>xapi [label="session.get_uuid"];
Feb 16 00:50:10 silver xapi: [debug|silver|12931 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.get_uuid 
D:200f4b1b657c created by task D:4f2a236c3d51
Feb 16 00:50:10 silver xapi: [ info|silver|12938 UNIX 
/var/lib/xcp/xapi|session.logout D:63b601db41d4|xapi] Session.destroy 
trackid=a4ad8fb26ffc6e4394f0453c9f565ac6
Feb 16 00:50:10 silver SM: [31267] ['/usr/lib/blktap/sbin/tap-ctl', 
'allocate']
Feb 16 00:50:10 silver SM: [31267]  = 0
Feb 16 00:50:10 silver SM: [31267] ['/usr/lib/blktap/sbin/tap-ctl', 'spawn']
Feb 16 00:50:10 silver tapdisk: tap-err:tapdisk_server_init: Failed to 
initialize low memory handler: No such file or directory
Feb 16 00:50:10 silver tapdisk[31293]: tapdisk-control: init, 10 x 4k 
buffers
Feb 16 00:50:10 silver tapdisk[31293]: I/O queue driver: lio
Feb 16 00:50:10 silver tapdisk[31293]: tapdisk-log: started, level 0
Feb 16 00:50:10 silver tapdisk[31293]: nbd: Set up local unix domain 
socket on path '/var/run/blktap-control/nbdclient31293'
Feb 16 00:50:10 silver SM: [31267]  = 0
Feb 16 00:50:10 silver SM: [31267] ['/usr/lib/blktap/sbin/tap-ctl', 
'attach', '-p', '31293', '-m', '0']
Feb 16 00:50:10 silver tapdisk[31293]: received 'attach' message (uuid = 0)
Feb 16 00:50:10 silver tapdisk[31293]: sending 'attach response' message 
(uuid = 0)
Feb 16 00:50:10 silver SM: [31267]  = 0
Feb 16 00:50:10 silver SM: [31267] ['/usr/lib/blktap/sbin/tap-ctl', 
'open', '-p', '31293', '-m', '0', '-a', 
'aio:/mnt/images/ISOs/ubuntu-14.04.1-server-amd64.iso', '-R']
Feb 16 00:50:10 silver tapdisk[31293]: received 'open' message (uuid = 0)
Feb 16 00:50:10 silver tapdisk[31293]: block-aio 
open('/mnt/images/ISOs/ubuntu-14.04.1-server-amd64.iso')
Feb 16 00:50:10 silver tapdisk[31293]: 
open(/mnt/images/ISOs/ubuntu-14.04.1-server-amd64.iso) with O_DIRECT
Feb 16 00:50:10 silver tapdisk[31293]: Image size: #012#011pre 
sector_shift  [599785472]#012#011post sector_shift [1171456]
Feb 16 00:50:10 silver tapdisk[31293]: opened image 
/mnt/images/ISOs/ubuntu-14.04.1-server-amd64.iso (1 users, state: 
0x00000003, type: 0, ro)
Feb 16 00:50:10 silver tapdisk[31293]: VBD CHAIN:
Feb 16 00:50:10 silver tapdisk[31293]: 
/mnt/images/ISOs/ubuntu-14.04.1-server-amd64.iso: type:aio(0) 
storage:n/a(-1)
Feb 16 00:50:10 silver tapdisk[31293]: bdev: capacity=1171456 
sector_size=512/512 flags=0x1
Feb 16 00:50:10 silver tapdisk[31293]: nbd: Set up local unix domain 
socket on path '/var/run/blktap-control/nbdserver31293.0'
Feb 16 00:50:10 silver tapdisk[31293]: nbd: NBD server unpause(0x6ff180) 
- fdrecv_listening_fd -1, unix_listening_fd=15
Feb 16 00:50:10 silver tapdisk[31293]: nbd: registering for 
unix_listening_fd
Feb 16 00:50:10 silver tapdisk[31293]: nbd: Successfully started NBD 
server on /var/run/blktap-control/nbd31293.0
Feb 16 00:50:10 silver tapdisk[31293]: sending 'open response' message 
(uuid = 0)
Feb 16 00:50:10 silver SM: [31267]  = 0
Feb 16 00:50:10 silver kernel: [107535.777856] block tda: sector-size: 
512/512+0 capacity: 1171456 discard: 0+0 flush: 0x0
Feb 16 00:50:10 silver SM: [31267] tap.activate: Launched 
Tapdisk(aio:/mnt/images/ISOs/ubuntu-14.04.1-server-amd64.iso, pid=31293, 
minor=0, state=R)
Feb 16 00:50:10 silver SM: [31267] Attempt to register tapdisk with RRDD 
as a plugin.
Feb 16 00:50:10 silver SM: [31267] ERROR: Failed to register tapdisk 
with RRDD due to [Errno 2] No such file or directory
Feb 16 00:50:10 silver SM: [31267] 
DeviceNode(/dev/sm/backend/0e141376-6525-ff18-ffee-862446f5a617/29327dc0-7397-4906-bcc9-1868a001a55c) 
-> /dev/xen/blktap-2/tapdev0
Feb 16 00:50:10 silver SM: [31267] result: {'params': 
'/dev/sm/backend/0e141376-6525-ff18-ffee-862446f5a617/29327dc0-7397-4906-bcc9-1868a001a55c', 
'xenstore_data': {'scsi/0x12/0x80': 'AIAAEjI5MzI3ZGMwLTczOTctNDkgIA==', 
'scsi/0x12/0x83': 
'AIMAMQIBAC1YRU5TUkMgIDI5MzI3ZGMwLTczOTctNDkwNi1iY2M5LTE4NjhhMDAxYTU1YyA=', 
'vdi-uuid': '29327dc0-7397-4906-bcc9-1868a001a55c', 'mem-pool': 
'0e141376-6525-ff18-ffee-862446f5a617'}}
Feb 16 00:50:10 silver SM: [31267] lock: closed 
/var/lock/sm/29327dc0-7397-4906-bcc9-1868a001a55c/vdi
Feb 16 00:50:10 silver xapi: [ info|silver|12917|sm_exec 
D:c9323ac816a3|xapi] Session.destroy 
trackid=b22128e9d207c07e523281a816915b9e
Feb 16 00:50:10 silver xapi: [debug|silver|12916||storage_impl] 
dbg:attach_and_activate dp:vbd/346f48e4-5d8c-1d72-487a-c33565175be7/xvdb 
sr:0e141376-6525-ff18-ffee-862446f5a617 
vdi:ubuntu-14.04.1-server-amd64.iso superstate:attached  RO
Feb 16 00:50:10 silver xapi: [ info|silver|12939||storage_impl] 
VDI.activate dbg:attach_and_activate 
dp:vbd/346f48e4-5d8c-1d72-487a-c33565175be7/xvdb 
sr:0e141376-6525-ff18-ffee-862446f5a617 vdi:ubuntu-14.04.1-server-amd64.iso
Feb 16 00:50:10 silver xapi: [debug|silver|12940||dummytaskhelper] task 
VDI.activate D:c278dc6b055c created by task attach_and_activate
Feb 16 00:50:10 silver xapi: [debug|silver|12940|VDI.activate 
D:c278dc6b055c|dummytaskhelper] task VDI.activate D:d97833b0cf8d created 
by task attach_and_activate
Feb 16 00:50:10 silver xapi: [ info|silver|12940|VDI.activate 
D:c278dc6b055c|storage_access] 
vbd/346f48e4-5d8c-1d72-487a-c33565175be7/xvdb 
sr:OpaqueRef:202bd8e5-96ab-a7b7-5859-e39088f07896 does not support 
vdi_activate: doing nothing
Feb 16 00:50:10 silver xapi: [debug|silver|12939||storage_impl] 
dbg:attach_and_activate dp:vbd/346f48e4-5d8c-1d72-487a-c33565175be7/xvdb 
sr:0e141376-6525-ff18-ffee-862446f5a617 
vdi:ubuntu-14.04.1-server-amd64.iso superstate:activated RO
Feb 16 00:50:10 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops] VIF.pre_plug
Feb 16 00:50:10 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops] Calling Xenlight.Domain.create_new
Feb 16 00:50:10 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_create.c:1342:do_domain_create: ao 
0x7f9624000c20: create: how=(nil) callback=(nil) poller=0x7f96300038a0
Feb 16 00:50:10 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_device.c:251:libxl__device_disk_set_backend: Disk vdev=xvda 
spec.backend=phy
Feb 16 00:50:10 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_device.c:189:disk_try_backend: Disk 
vdev=xvda, uses script=... assuming phy backend
Feb 16 00:50:10 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_device.c:251:libxl__device_disk_set_backend: Disk vdev=xvdb 
spec.backend=phy
Feb 16 00:50:10 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_device.c:189:disk_try_backend: Disk 
vdev=xvdb, uses script=... assuming phy backend
Feb 16 00:50:10 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_create.c:797:initiate_domain_create: 
running bootloader
Feb 16 00:50:10 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_bootloader.c:327:libxl__bootloader_run: no bootloader configured, 
using user supplied kernel
Feb 16 00:50:10 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_event.c:618:libxl__ev_xswatch_deregister: watch w=0x7f9624000fc8: 
deregister unregistered
Feb 16 00:50:10 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_numa.c:478:libxl__get_numa_candidate: 
New best NUMA placement candidate found: nr_nodes=1, nr_cpus=8, 
nr_vcpus=9, free_memkb=24235
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_dom.c:195:numa_place_domain: NUMA 
placement candidate with 1 nodes, 8 cpus and 24235 KB free selected
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_allocate: 
cmdline="file=/cdrom/preseed/ubuntu-server.seed quiet --  
ip=10.99.99.9::10.99.99.1:255.255.255.0:trusty dns0=109.95.202.2 
ns=109.95.202.2 noipv6 ks=http://10.99.99.1:1080/xen.ks ksdevice=eth0", 
features="(null)"
Feb 16 00:50:10 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_dom.c:357:libxl__build_pv: pv kernel 
mapped 0 path /var/run/xend/boot/boot_kernel.IBEwLX
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_kernel_file: 
filename="/var/run/xend/boot/boot_kernel.IBEwLX"
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_malloc_filemap    : 5664 kB
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_ramdisk_file: 
filename="/var/run/xend/boot/boot_ramdisk.eAg7bd"
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_malloc_filemap    : 10047 kB
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_boot_xen_init: ver 4.4, caps 
xen-3.0-x86_64 xen-3.0-x86_32p hvm-3.0-x86_32 hvm-3.0-x86_32p hvm-3.0-x86_64
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_parse_image: called
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_find_loader: trying 
multiboot-binary loader ...
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: loader probe failed
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_find_loader: trying Linux 
bzImage loader ...
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_malloc            : 18906 kB
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_do_gunzip: unzip ok, 
0x57b3f4 -> 0x12769b8
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: loader probe OK
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_parse_binary: phdr: paddr=0x1000000 
memsz=0xb52000
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_parse_binary: phdr: paddr=0x1c00000 
memsz=0x11e0f0
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_parse_binary: phdr: paddr=0x1d1f000 
memsz=0x15140
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_parse_binary: phdr: paddr=0x1d35000 
memsz=0x6cc000
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_parse_binary: memory: 0x1000000 -> 0x2401000
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_xen_parse_note: GUEST_OS = "linux"
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_xen_parse_note: GUEST_VERSION = "2.6"
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_xen_parse_note: XEN_VERSION = "xen-3.0"
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_xen_parse_note: VIRT_BASE = 0xffffffff80000000
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_xen_parse_note: ENTRY = 0xffffffff81d351f0
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_xen_parse_note: HYPERCALL_PAGE = 
0xffffffff81001000
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_xen_parse_note: FEATURES = 
"!writable_page_tables|pae_pgdir_above_4gb"
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_xen_parse_note: PAE_MODE = "yes"
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_xen_parse_note: LOADER = "generic"
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_xen_parse_note: unknown xen elf note (0xd)
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_xen_parse_note: SUSPEND_CANCEL = 0x1
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_xen_parse_note: HV_START_LOW = 
0xffff800000000000
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_xen_parse_note: PADDR_OFFSET = 0x0
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_xen_addr_calc_check: addresses:
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: virt_base        = 0xffffffff80000000
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_paddr_offset = 0x0
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: virt_offset      = 0xffffffff80000000
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: virt_kstart      = 0xffffffff81000000
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: virt_kend        = 0xffffffff82401000
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: virt_entry       = 0xffffffff81d351f0
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: p2m_base         = 0xffffffffffffffff
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_parse_elf_kernel: 
xen-3.0-x86_64: 0xffffffff81000000 -> 0xffffffff82401000
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_mem_init: mem 512 MB, pages 
0x20000 pages, 4k each
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_mem_init: 0x20000 pages
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_boot_mem_init: called
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: x86_compat: guest xen-3.0-x86_64, 
address size 64
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_malloc            : 1024 kB
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_build_image: called
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_alloc_segment:   
kernel       : 0xffffffff81000000 -> 0xffffffff82401000  (pfn 0x1000 + 
0x1401 pages)
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_malloc            : 120 kB
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_pfn_to_ptr_retcount: domU 
mapping: pfn 0x1000+0x1401 at 0x7f9620a2c000
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_load_binary: phdr 0 at 0x7f9620a2c000 -> 
0x7f962157e000
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_load_binary: phdr 1 at 0x7f962162c000 -> 
0x7f962174a0f0
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_load_binary: phdr 2 at 0x7f962174b000 -> 
0x7f9621760140
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] xc: elf_load_binary: phdr 3 at 0x7f9621761000 -> 
0x7f96218a2000
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_alloc_segment:   
ramdisk      : 0xffffffff82401000 -> 0xffffffff83ef5000  (pfn 0x2401 + 
0x1af4 pages)
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_malloc            : 161 kB
Feb 16 00:50:10 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_pfn_to_ptr_retcount: domU 
mapping: pfn 0x2401+0x1af4 at 0x7f961250c000
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_do_gunzip: unzip ok, 
0x9cfe3a -> 0x1af3e10
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_alloc_segment:   
phys2mach    : 0xffffffff83ef5000 -> 0xffffffff83ff5000  (pfn 0x3ef5 + 
0x100 pages)
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_pfn_to_ptr_retcount: domU 
mapping: pfn 0x3ef5+0x100 at 0x7f96580cd000
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_alloc_page   :   start 
info   : 0xffffffff83ff5000 (pfn 0x3ff5)
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_alloc_page   :   
xenstore     : 0xffffffff83ff6000 (pfn 0x3ff6)
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_alloc_page   :   
console      : 0xffffffff83ff7000 (pfn 0x3ff7)
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: nr_page_tables: 
0x0000ffffffffffff/48: 0xffff000000000000 -> 0xffffffffffffffff, 1 table(s)
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: nr_page_tables: 
0x0000007fffffffff/39: 0xffffff8000000000 -> 0xffffffffffffffff, 1 table(s)
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: nr_page_tables: 
0x000000003fffffff/30: 0xffffffff80000000 -> 0xffffffffbfffffff, 1 table(s)
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: nr_page_tables: 
0x00000000001fffff/21: 0xffffffff80000000 -> 0xffffffff843fffff, 34 table(s)
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_alloc_segment:   page 
tables  : 0xffffffff83ff8000 -> 0xffffffff8401d000  (pfn 0x3ff8 + 0x25 
pages)
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_pfn_to_ptr_retcount: domU 
mapping: pfn 0x3ff8+0x25 at 0x7f965f1c6000
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_alloc_page   :   boot 
stack   : 0xffffffff8401d000 (pfn 0x401d)
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_build_image  : 
virt_alloc_end : 0xffffffff8401e000
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_build_image  : 
virt_pgtab_end : 0xffffffff84400000
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_boot_image: called
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: arch_setup_bootearly: doing nothing
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_compat_check: supported 
guest type: xen-3.0-x86_64 <= matches
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_compat_check: supported 
guest type: xen-3.0-x86_32p
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_compat_check: supported 
guest type: hvm-3.0-x86_32
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_compat_check: supported 
guest type: hvm-3.0-x86_32p
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_compat_check: supported 
guest type: hvm-3.0-x86_64
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_update_guest_p2m: dst 64bit, 
pages 0x20000
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: clear_page: pfn 0x3ff7, mfn 0x40876e
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: clear_page: pfn 0x3ff6, mfn 0x40876f
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_pfn_to_ptr_retcount: domU 
mapping: pfn 0x3ff5+0x1 at 0x7f965f1f3000
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: start_info_x86_64: called
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: setup_hypercall_page: 
vaddr=0xffffffff81001000 pfn=0x1001
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: domain builder memory footprint
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder:    allocated
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder:       malloc             : 20222 kB
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder:       anon mmap          : 0 bytes
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder:    mapped
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder:       file mmap          : 15711 kB
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder:       domU mmap          : 48 MB
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: arch_setup_bootlate: shared_info: 
pfn 0x0, mfn 0xbf2e3
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: shared_info_x86_64: called
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: vcpu_x86_64: called
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: vcpu_x86_64: cr3: pfn 0x3ff8 mfn 
0x40876d
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: launch_vm: called, ctxt=0x7f965f1c4004
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|libxl] domainbuilder: xc_dom_release: called
Feb 16 00:50:11 silver xenopsd-xc: [debug|silver|5||xenstore_watch] 
Current domains: 0, 13
Feb 16 00:50:11 silver xenopsd-xc: [debug|silver|5||xenstore_watch] 
Domain 12 may have changed state
Feb 16 00:50:11 silver squeezed: [debug|silver|3||xenops] Adding watches 
for domid: 13
Feb 16 00:50:11 silver xenopsd-xc: [debug|silver|5||xenstore_watch] 
However domain 12 is not managed by us: ignoring
Feb 16 00:50:11 silver xenopsd-xc: [debug|silver|5||xenstore_watch] 
Domain 13 may have changed state
Feb 16 00:50:11 silver xenopsd-xc: [debug|silver|5||xenstore_watch] 
However domain 13 is not managed by us: ignoring
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] Domain 
13 may have changed state
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] Adding 
watches for: domid 13
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /local/domain/13/data/updated
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|events|xenops_server] Received an event on managed VM 
346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|queue|xenops_server] Queue.push ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"] onto redirected 
346f48e4-5d8c-1d72-487a-c33565175be7:[ ["Atomic", ["VM_unpause", 
"346f48e4-5d8c-1d72-487a-c33565175be7"]] ]
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /local/domain/13/memory/target
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_device.c:251:libxl__device_disk_set_backend: Disk vdev=xvda 
spec.backend=phy
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_device.c:189:disk_try_backend: Disk 
vdev=xvda, uses script=... assuming phy backend
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /local/domain/13/memory/uncooperative
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /local/domain/13/console/vnc-port
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /local/domain/13/console/tc-port
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /local/domain/13/device
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /local/domain/13/vm-data
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /vm/346f48e4-5d8c-1d72-487a-c33565175be7/rtc/timeoffset
Feb 16 00:50:11 silver squeezed: [debug|silver|3||xenops] watch 
/memory/initial-reservation <- None
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|events|xenops_server] Received an event on managed VM 
346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|queue|xenops_server] Queue.push ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"] onto redirected 
346f48e4-5d8c-1d72-487a-c33565175be7:[ ["Atomic", ["VM_unpause", 
"346f48e4-5d8c-1d72-487a-c33565175be7"]], ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"] ]
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|events|xenops_server] Received an event on managed VM 
346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|queue|xenops_server] Queue.push ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"] onto redirected 
346f48e4-5d8c-1d72-487a-c33565175be7:[ ["Atomic", ["VM_unpause", 
"346f48e4-5d8c-1d72-487a-c33565175be7"]], ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"] ]
Feb 16 00:50:11 silver squeezed: [debug|silver|3||xenops] watch 
/memory/target <- 524288
Feb 16 00:50:11 silver squeezed: [debug|silver|3||xenops] watch 
/control/feature-balloon <- None
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|events|xenops_server] Received an event on managed VM 
346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|queue|xenops_server] Queue.push ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"] onto redirected 
346f48e4-5d8c-1d72-487a-c33565175be7:[ ["Atomic", ["VM_unpause", 
"346f48e4-5d8c-1d72-487a-c33565175be7"]], ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"] ]
Feb 16 00:50:11 silver squeezed: [debug|silver|3||xenops] watch 
/data/updated <- None
Feb 16 00:50:11 silver squeezed: [debug|silver|3||xenops] watch 
/memory/memory-offset <- None
Feb 16 00:50:11 silver squeezed: [debug|silver|3||xenops] watch 
/memory/uncooperative <- None
Feb 16 00:50:11 silver squeezed: [debug|silver|3||xenops] watch 
/memory/dynamic-min <- None
Feb 16 00:50:11 silver squeezed: [debug|silver|3||xenops] watch 
/memory/dynamic-max <- None
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl_events] EVENTREG: registering timeout (1424044221s, 
196338us), token = timeout157
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|6||libxl_events] 
EVENTLOOP: poll interrupted for update
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_event.c:570:libxl__ev_xswatch_register: watch w=0x7f9624002968 
wpath=/local/domain/0/backend/vbd/13/51712/state token=3/9c: register 
slotnum=3
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|6||libxl_events] 
EVENTLOOP: calling poll with timeout value 10000 (ms)
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|6||libxl_events] 
EVENTLOOP: fd event occurred, token = fd1
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_device.c:251:libxl__device_disk_set_backend: Disk vdev=xvdb 
spec.backend=phy
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_device.c:189:disk_try_backend: Disk 
vdev=xvdb, uses script=... assuming phy backend
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] Adding 
watches for: frontend (domid=13 | kind=vbd | devid=51712); backend 
(domid=0 | kind=vbd | devid=51712)
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /local/domain/0/backend/vbd/13/51712/kthread-pid
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /local/domain/0/backend/vbd/13/51712/tapdisk-pid
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /local/domain/0/backend/vbd/13/51712/shutdown-done
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /local/domain/0/backend/vbd/13/51712/params
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] Watch 
on backend domid: 0 kind: vbd -> frontend domid: 13 devid: 51712
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_device.c:251:libxl__device_disk_set_backend: Disk vdev=xvdb 
spec.backend=phy
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] Watch 
on backend domid: 0 kind: vbd -> frontend domid: 13 devid: 51712
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_device.c:189:disk_try_backend: Disk 
vdev=xvdb, uses script=... assuming phy backend
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|events|xenops_server] Received an event on managed VBD 
346f48e4-5d8c-1d72-487a-c33565175be7.xvda
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] Watch 
on backend domid: 0 kind: vbd -> frontend domid: 13 devid: 51712
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|queue|xenops_server] Queue.push ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvda"]] onto redirected 
346f48e4-5d8c-1d72-487a-c33565175be7:[ ["Atomic", ["VM_unpause", 
"346f48e4-5d8c-1d72-487a-c33565175be7"]], ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"] ]
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] Watch 
on backend domid: 0 kind: vbd -> frontend domid: 13 devid: 51712
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|events|xenops_server] Received an event on managed VBD 
346f48e4-5d8c-1d72-487a-c33565175be7.xvda
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|queue|xenops_server] Queue.push ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvda"]] onto redirected 
346f48e4-5d8c-1d72-487a-c33565175be7:[ ["Atomic", ["VM_unpause", 
"346f48e4-5d8c-1d72-487a-c33565175be7"]], ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"], ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvda"]] ]
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl_events] EVENTREG: registering timeout (1424044221s, 
215195us), token = timeout158
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_event.c:570:libxl__ev_xswatch_register: watch w=0x7f96240037a8 
wpath=/local/domain/0/backend/vbd/13/51728/state token=1/9d: register 
slotnum=1
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_create.c:1356:do_domain_create: ao 
0x7f9624000c20: inprogress: poller=0x7f96300038a0, flags=i
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_event.c:514:watchfd_callback: watch 
w=0x7f9624002968 wpath=/local/domain/0/backend/vbd/13/51712/state 
token=3/9c: event epath=/local/domain/0/backend/vbd/13/51712/state
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_event.c:653:devstate_watch_callback: 
backend /local/domain/0/backend/vbd/13/51712/state wanted state 2 ok
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl_events] EVENTREG: triggering timeout, token = 
timeout157
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] Adding 
watches for: frontend (domid=13 | kind=vbd | devid=51728); backend 
(domid=0 | kind=vbd | devid=51728)
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_event.c:606:libxl__ev_xswatch_deregister: watch w=0x7f9624002968 
wpath=/local/domain/0/backend/vbd/13/51712/state token=3/9c: deregister 
slotnum=3
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /local/domain/0/backend/vbd/13/51728/kthread-pid
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /local/domain/0/backend/vbd/13/51728/tapdisk-pid
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_event.c:618:libxl__ev_xswatch_deregister: watch w=0x7f9624002968: 
deregister unregistered
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /local/domain/0/backend/vbd/13/51728/shutdown-done
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /local/domain/0/backend/vbd/13/51728/params
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_event.c:618:libxl__ev_xswatch_deregister: watch w=0x7f96240029f0: 
deregister unregistered
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_event.c:483:watchfd_callback: watch 
epath=/local/domain/0/backend/vbd/13/51712/state token=3/9c: empty slot
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_event.c:514:watchfd_callback: watch 
w=0x7f96240037a8 wpath=/local/domain/0/backend/vbd/13/51728/state 
token=1/9d: event epath=/local/domain/0/backend/vbd/13/51728/state
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_event.c:653:devstate_watch_callback: 
backend /local/domain/0/backend/vbd/13/51728/state wanted state 2 ok
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl_events] EVENTREG: triggering timeout, token = 
timeout158
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_event.c:606:libxl__ev_xswatch_deregister: watch w=0x7f96240037a8 
wpath=/local/domain/0/backend/vbd/13/51728/state token=1/9d: deregister 
slotnum=1
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_event.c:618:libxl__ev_xswatch_deregister: watch w=0x7f96240037a8: 
deregister unregistered
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_event.c:618:libxl__ev_xswatch_deregister: watch w=0x7f9624003830: 
deregister unregistered
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] Watch 
on backend domid: 0 kind: vbd -> frontend domid: 13 devid: 51728
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] Watch 
on backend domid: 0 kind: vbd -> frontend domid: 13 devid: 51728
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|events|xenops_server] Received an event on managed VBD 
346f48e4-5d8c-1d72-487a-c33565175be7.xvdb
Feb 16 00:50:11 silver logger: /etc/xen/scripts/block: add 
XENBUS_PATH=backend/vbd/13/51712
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] Watch 
on backend domid: 0 kind: vbd -> frontend domid: 13 devid: 51728
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|queue|xenops_server] Queue.push ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvdb"]] onto redirected 
346f48e4-5d8c-1d72-487a-c33565175be7:[ ["Atomic", ["VM_unpause", 
"346f48e4-5d8c-1d72-487a-c33565175be7"]], ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"], ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvda"]] ]
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|events|xenops_server] Received an event on managed VBD 
346f48e4-5d8c-1d72-487a-c33565175be7.xvdb
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|queue|xenops_server] Queue.push ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvdb"]] onto redirected 
346f48e4-5d8c-1d72-487a-c33565175be7:[ ["Atomic", ["VM_unpause", 
"346f48e4-5d8c-1d72-487a-c33565175be7"]], ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"], ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvda"]], ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvdb"]] ]
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] Watch 
on backend domid: 0 kind: vbd -> frontend domid: 13 devid: 51728
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|events|xenops_server] Received an event on managed VBD 
346f48e4-5d8c-1d72-487a-c33565175be7.xvdb
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|queue|xenops_server] Queue.push ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvdb"]] onto redirected 
346f48e4-5d8c-1d72-487a-c33565175be7:[ ["Atomic", ["VM_unpause", 
"346f48e4-5d8c-1d72-487a-c33565175be7"]], ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"], ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvda"]], ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvdb"]] ]
Feb 16 00:50:11 silver logger: /etc/xen/scripts/block: add 
XENBUS_PATH=backend/vbd/13/51728
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl_events] EVENTREG: registering timeout (1424044221s, 
247096us), token = timeout159
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_event.c:570:libxl__ev_xswatch_register: watch w=0x7f9624005d08 
wpath=/local/domain/0/backend/vif/13/0/state token=1/9e: register slotnum=1
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_event.c:489:watchfd_callback: watch 
w=0x7f9624005d08 epath=/local/domain/0/backend/vbd/13/51728/state 
token=1/9d: counter != 9e
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_event.c:514:watchfd_callback: watch 
w=0x7f9624005d08 wpath=/local/domain/0/backend/vif/13/0/state 
token=1/9e: event epath=/local/domain/0/backend/vif/13/0/state
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_event.c:657:devstate_watch_callback: 
backend /local/domain/0/backend/vif/13/0/state wanted state 2 still 
waiting state 1
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|6||libxl_events] 
EVENTLOOP: calling poll with timeout value 10000 (ms)
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|6||libxl_events] 
EVENTLOOP: poll interrupted for update
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|6||libxl_events] 
EVENTLOOP: calling poll with timeout value 10000 (ms)
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] Adding 
watches for: frontend (domid=13 | kind=vif | devid=0); backend (domid=0 
| kind=vif | devid=0)
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /local/domain/0/backend/vif/13/0/kthread-pid
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /local/domain/0/backend/vif/13/0/tapdisk-pid
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|6||libxl_events] 
EVENTLOOP: fd event occurred, token = fd1
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_event.c:514:watchfd_callback: watch 
w=0x7f9624005d08 wpath=/local/domain/0/backend/vif/13/0/state 
token=1/9e: event epath=/local/domain/0/backend/vif/13/0/state
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /local/domain/0/backend/vif/13/0/shutdown-done
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_event.c:653:devstate_watch_callback: 
backend /local/domain/0/backend/vif/13/0/state wanted state 2 ok
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl_events] EVENTREG: triggering timeout, token = 
timeout159
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_event.c:606:libxl__ev_xswatch_deregister: watch w=0x7f9624005d08 
wpath=/local/domain/0/backend/vif/13/0/state token=1/9e: deregister 
slotnum=1
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_event.c:618:libxl__ev_xswatch_deregister: watch w=0x7f9624005d08: 
deregister unregistered
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] 
xenstore watch /local/domain/0/backend/vif/13/0/params
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_event.c:618:libxl__ev_xswatch_deregister: watch w=0x7f9624005d90: 
deregister unregistered
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: 
libxl_event.c:1761:libxl__ao_progress_report: ao 0x7f9624000c20: 
progress report: ignored
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_event.c:1591:libxl__ao_complete: ao 
0x7f9624000c20: complete, rc=0
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|libxl] libxl: libxl_event.c:1563:libxl__ao__destroy: ao 
0x7f9624000c20: destroy
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops] Call Xenlight.Domain.create_new completed
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops] Xenlight has created domain 13
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|6||libxl_events] 
EVENTLOOP: calling poll with timeout value 0 (ms)
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|6||libxl_events] 
EVENTLOOP: poll interrupted for update
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|6||libxl_events] 
EVENTLOOP: calling poll with timeout value 0 (ms)
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|6||libxl_events] 
EVENTLOOP: timeout occurred, token = timeout159
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|6||libxl_events] 
EVENTLOOP: calling poll with timeout value 0 (ms)
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|6||libxl_events] 
EVENTLOOP: timeout occurred, token = timeout158
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|6||libxl_events] 
EVENTLOOP: calling poll with timeout value 0 (ms)
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|6||libxl_events] 
EVENTLOOP: timeout occurred, token = timeout157
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|6||libxl_events] 
EVENTLOOP: calling poll with timeout value -1 (ms)
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|hotplug] Hotplug.wait_for_plug: frontend (domid=13 | 
kind=vif | devid=0); backend (domid=0 | kind=vif | devid=0)
Feb 16 00:50:11 silver ntpdate[30998]: step time server 193.25.222.240 
offset -0.000590 sec
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|7||xenops] Watch 
on backend domid: 0 kind: vif -> frontend domid: 13 devid: 0
Feb 16 00:50:11 silver xenopsd-xenlight: message repeated 3 times: [ 
[debug|silver|7||xenops] Watch on backend domid: 0 kind: vif -> frontend 
domid: 13 devid: 0]
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|events|xenops_server] Received an event on managed VIF 
346f48e4-5d8c-1d72-487a-c33565175be7.0
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|queue|xenops_server] Queue.push ["VIF_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "0"]] onto redirected 
346f48e4-5d8c-1d72-487a-c33565175be7:[ ["Atomic", ["VM_unpause", 
"346f48e4-5d8c-1d72-487a-c33565175be7"]], ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"], ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvda"]], ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvdb"]] ]
Feb 16 00:50:11 silver logger: /etc/xen/scripts/block: Writing 
backend/vbd/13/51712/hotplug-error /mnt/images/SRFFS/manual is not a 
block device. backend/vbd/13/51712/hotplug-status error to xenstore.
Feb 16 00:50:11 silver logger: /etc/xen/scripts/block: 
/mnt/images/SRFFS/manual is not a block device.
Feb 16 00:50:11 silver vif-real: Called as: /usr/lib/xenopsd/vif-real 
vif 13 0 online
Feb 16 00:50:11 silver ntpd[31427]: ntpd 4.2.6p5@xxxxxxxx Fri Feb  6 
15:24:25 UTC 2015 (1)
Feb 16 00:50:11 silver ntpd[31434]: proto: precision = 0.903 usec
Feb 16 00:50:11 silver ntpd[31434]: ntp_io: estimated max descriptors: 
1024, initial socket boundary: 16
Feb 16 00:50:11 silver ntpd[31434]: Listen and drop on 0 v4wildcard 
0.0.0.0 UDP 123
Feb 16 00:50:11 silver ntpd[31434]: Listen and drop on 1 v6wildcard :: 
UDP 123
Feb 16 00:50:11 silver ntpd[31434]: Listen normally on 2 lo 127.0.0.1 
UDP 123
Feb 16 00:50:11 silver ntpd[31434]: Listen normally on 3 brem1 
109.95.203.3 UDP 123
Feb 16 00:50:11 silver ntpd[31434]: Listen normally on 4 brem1 
109.95.203.4 UDP 123
Feb 16 00:50:11 silver ntpd[31434]: Listen normally on 5 brem1 
109.95.203.6 UDP 123
Feb 16 00:50:11 silver ntpd[31434]: Listen normally on 6 tun0 
10.20.255.40 UDP 123
Feb 16 00:50:11 silver ntpd[31434]: Listen normally on 7 xapi0 
10.99.99.1 UDP 123
Feb 16 00:50:11 silver ntpd[31434]: peers refreshed
Feb 16 00:50:11 silver ntpd[31434]: Listening on routing socket on fd 
#24 for interface updates
Feb 16 00:50:11 silver scripts-vif: Called as "vif 13 0 online" domid:13 
devid:0 mode:bridge
Feb 16 00:50:11 silver scripts-vif: Setting vif13.0 MTU 1500
Feb 16 00:50:11 silver scripts-vif: Adding vif13.0 to xapi0 with address 
fe:ff:ff:ff:ff:ff
Feb 16 00:50:11 silver logger: /etc/xen/scripts/block: Writing 
backend/vbd/13/51728/physical-device fb:0 to xenstore.
Feb 16 00:50:11 silver logger: /etc/xen/scripts/block: Writing 
backend/vbd/13/51728/hotplug-status connected to xenstore.
Feb 16 00:50:11 silver kernel: [107536.510237] device vif13.0 entered 
promiscuous mode
Feb 16 00:50:11 silver setup-vif-rules: 
/usr/lib/xenopsd/setup-vif-rules[31492] - common.py: Detected network 
backend as: 'bridge'
Feb 16 00:50:11 silver setup-vif-rules: 
/usr/lib/xenopsd/setup-vif-rules[31492] - Called with interface=vif13.0, 
uuid=346f48e4-5d8c-1d72-487a-c33565175be7, devid=0, network_mode=bridge, 
action=filter
Feb 16 00:50:11 silver setup-vif-rules: 
/usr/lib/xenopsd/setup-vif-rules[31492] - attempting to acquire lock 
/var/lock/ebtables.lock
Feb 16 00:50:11 silver setup-vif-rules: 
/usr/lib/xenopsd/setup-vif-rules[31492] - acquired lock 
/var/lock/ebtables.lock
Feb 16 00:50:11 silver setup-vif-rules: 
/usr/lib/xenopsd/setup-vif-rules[31492] - ['/sbin/ip', 'link', 'set', 
'vif13.0', 'down']
Feb 16 00:50:11 silver setup-vif-rules: 
/usr/lib/xenopsd/setup-vif-rules[31492] - ['ebtables', '-L', 
'FORWARD_vif13.0']
Feb 16 00:50:11 silver setup-vif-rules: 
/usr/lib/xenopsd/setup-vif-rules[31492] - Got locking config: 
{'ipv4_allowed': [], 'mac': u'7a:14:1b:59:3b:98', 'ipv6_allowed': [], 
'locking_mode': u'unlocked'}
Feb 16 00:50:11 silver setup-vif-rules: 
/usr/lib/xenopsd/setup-vif-rules[31492] - ['/sbin/ip', 'link', 'set', 
'vif13.0', 'up']
Feb 16 00:50:11 silver kernel: [107536.574999] IPv6: 
ADDRCONF(NETDEV_UP): vif13.0: link is not ready
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|10||scheduler] 
Scheduler sleep until 1424044234 (another 22 seconds)
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|hotplug] Synchronised ok with hotplug script: frontend 
(domid=13 | kind=vif | devid=0); backend (domid=0 | kind=vif | devid=0)
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|hotplug] Hotplug.wait_for_plug: frontend (domid=13 | 
kind=vbd | devid=51712); backend (domid=0 | kind=vbd | devid=51712)
Feb 16 00:50:11 silver script-vif: vif13.0: writing 
backend/vif/13/0/hotplug-status=connected
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|10||scheduler] 
Scheduler sleep until 1424044234 (another 22 seconds)
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|hotplug] Synchronised ok with hotplug script: frontend 
(domid=13 | kind=vbd | devid=51712); backend (domid=0 | kind=vbd | 
devid=51712)
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|hotplug] Hotplug.wait_for_plug: frontend (domid=13 | 
kind=vbd | devid=51728); backend (domid=0 | kind=vbd | devid=51728)
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|10||scheduler] 
Scheduler sleep until 1424044234 (another 22 seconds)
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|hotplug] Synchronised ok with hotplug script: frontend 
(domid=13 | kind=vbd | devid=51728); backend (domid=0 | kind=vbd | 
devid=51728)
Feb 16 00:50:11 silver squeezed: [debug|silver|119||xenops] 
Xenctrl.domain_setmaxmem domid=13 max=530432 (was=525312)
Feb 16 00:50:11 silver squeezed: [debug|silver|3||xenops] watch 
/memory/initial-reservation <- 530432
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops] VM = 346f48e4-5d8c-1d72-487a-c33565175be7; domid 
= 13; set_memory_dynamic_range min = 524288; max = 524288
Feb 16 00:50:11 silver squeezed: [debug|silver|3||xenops] watch 
/memory/dynamic-min <- 524288
Feb 16 00:50:11 silver squeezed: [debug|silver|3||xenops] watch 
/memory/dynamic-max <- 524288
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|events|xenops_server] Received an event on managed VM 
346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|queue|xenops_server] Queue.push ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"] onto redirected 
346f48e4-5d8c-1d72-487a-c33565175be7:[ ["Atomic", ["VM_unpause", 
"346f48e4-5d8c-1d72-487a-c33565175be7"]], ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"], ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvda"]], ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvdb"]], ["VIF_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "0"]] ]
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops] In PV_Vnc.start
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops] delete_reservation 
24aba045-5a90-4994-ab1e-327607629251
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] TASK.signal 830 = ["Pending", 0.250000]
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] Performing: ["VBD_set_active", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvda"], true]
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] VBD.set_active 
346f48e4-5d8c-1d72-487a-c33565175be7.xvda true
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] VBD_DB.signal 
346f48e4-5d8c-1d72-487a-c33565175be7.xvda
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] TASK.signal 830 = ["Pending", 0.375000]
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] Performing: ["VBD_set_active", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvdb"], true]
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] VBD.set_active 
346f48e4-5d8c-1d72-487a-c33565175be7.xvdb true
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Task", "830"]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenops event on Task 830
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] VBD_DB.signal 
346f48e4-5d8c-1d72-487a-c33565175be7.xvdb
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] TASK.signal 830 = ["Pending", 0.500000]
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] Performing: ["VBD_epoch_begin", 
[["346f48e4-5d8c-1d72-487a-c33565175be7", "xvda"], ["VDI", 
"13d626f8-4a8b-e822-f821-de35f23d2886\/manual"]]]
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] VBD.epoch_begin ["VDI", 
"13d626f8-4a8b-e822-f821-de35f23d2886\/manual"]
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|xenops] Processing disk 
SR=13d626f8-4a8b-e822-f821-de35f23d2886 VDI=manual
Feb 16 00:50:11 silver xapi: [ info|silver|12942||storage_impl] 
VDI.epoch_begin dbg:Async.VM.start R:17052e888f20 
sr:13d626f8-4a8b-e822-f821-de35f23d2886 vdi:manual
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|10||scheduler] 
Scheduler sleep until 1424044234 (another 22 seconds)
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] TASK.signal 830 = ["Pending", 0.625000]
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] Performing: ["VBD_epoch_begin", 
[["346f48e4-5d8c-1d72-487a-c33565175be7", "xvdb"], ["VDI", 
"0e141376-6525-ff18-ffee-862446f5a617\/ubuntu-14.04.1-server-amd64.iso"]]]
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] VBD.epoch_begin ["VDI", 
"0e141376-6525-ff18-ffee-862446f5a617\/ubuntu-14.04.1-server-amd64.iso"]
Feb 16 00:50:11 silver xenopsd-xenlight: [ info|silver|11|Async.VM.start 
R:17052e888f20|xenops] Processing disk 
SR=0e141376-6525-ff18-ffee-862446f5a617 VDI=ubuntu-14.04.1-server-amd64.iso
Feb 16 00:50:11 silver xapi: [ info|silver|12943||storage_impl] 
VDI.epoch_begin dbg:Async.VM.start R:17052e888f20 
sr:0e141376-6525-ff18-ffee-862446f5a617 vdi:ubuntu-14.04.1-server-amd64.iso
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Vbd", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvda"]]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] ignoring xenops event on VBD 
346f48e4-5d8c-1d72-487a-c33565175be7.xvda
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Vbd", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvdb"]]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] ignoring xenops event on VBD 
346f48e4-5d8c-1d72-487a-c33565175be7.xvdb
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Task", "830"]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenops event on Task 830
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|events|xenops_server] Received an event on managed VM 
346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|queue|xenops_server] Queue.push ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"] onto redirected 
346f48e4-5d8c-1d72-487a-c33565175be7:[ ["Atomic", ["VM_unpause", 
"346f48e4-5d8c-1d72-487a-c33565175be7"]], ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"], ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvda"]], ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvdb"]], ["VIF_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "0"]] ]
Feb 16 00:50:11 silver xapi: [debug|silver|12944||dummytaskhelper] task 
VDI.epoch_begin D:90af62f1cf9f created by task R:tart R:1052e
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|events|xenops_server] Received an event on managed VM 
346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xapi: [debug|silver|12944|VDI.epoch_begin 
D:90af62f1cf9f|sm] SM iso vdi_epoch_begin 
sr=OpaqueRef:202bd8e5-96ab-a7b7-5859-e39088f07896 
vdi=OpaqueRef:dcbf7bbe-630a-57a3-2dd3-13dc63840151
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|3|queue|xenops_server] Queue.push ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"] onto redirected 
346f48e4-5d8c-1d72-487a-c33565175be7:[ ["Atomic", ["VM_unpause", 
"346f48e4-5d8c-1d72-487a-c33565175be7"]], ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"], ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvda"]], ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvdb"]], ["VIF_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "0"]] ]
Feb 16 00:50:11 silver xapi: [ info|silver|12944|sm_exec 
D:0013e8cabfd9|xapi] Session.create 
trackid=8444eb00454659e70ba6a9c1caa81f5b pool=false uname= originator= 
is_local_superuser=true auth_user_sid= 
parent=trackid=9834f5af41c964e225f24279aefe4e49
Feb 16 00:50:11 silver xapi: [debug|silver|12944|sm_exec 
D:0013e8cabfd9|mscgen] xapi=>xapi [label="session.get_uuid"];
Feb 16 00:50:11 silver xapi: [debug|silver|12945 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.get_uuid 
D:404b730b2688 created by task D:0013e8cabfd9
Feb 16 00:50:11 silver xapi: [debug|silver|12944|sm_exec 
D:0013e8cabfd9|mscgen] smapiv2=>smapiv1 [label="vdi_epoch_begin"];
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|10||scheduler] 
Scheduler sleep until 1424044234 (another 22 seconds)
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Task", "830"]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenops event on Task 830
Feb 16 00:50:11 silver xapi: [debug|silver|12946 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config 
D:3f06996b7e8f created by task D:90af62f1cf9f
Feb 16 00:50:11 silver SM: [31530] vdi_epoch_begin {'sr_uuid': 
'0e141376-6525-ff18-ffee-862446f5a617', 'subtask_of': 
'DummyRef:|90af62f1-cf9f-08d4-1430-79d46a6b3cbe|VDI.epoch_begin', 
'vdi_ref': 'OpaqueRef:dcbf7bbe-630a-57a3-2dd3-13dc63840151', 
'vdi_on_boot': 'persist', 'args': [], 'vdi_location': 
'ubuntu-14.04.1-server-amd64.iso', 'host_ref': 
'OpaqueRef:0d0d7bf7-4d03-afc4-4280-8724014224ba', 'session_ref': 
'OpaqueRef:12013316-4a30-7eb3-18a3-1e586c42be41', 'device_config': 
{'path': '/mnt/images/ISOs', 'legacy_mode': 'true', 'SRmaster': 'true', 
'location': '/mnt/images/ISOs'}, 'command': 'vdi_epoch_begin', 
'vdi_allow_caching': 'false', 'sr_ref': 
'OpaqueRef:202bd8e5-96ab-a7b7-5859-e39088f07896', 'vdi_uuid': 
'29327dc0-7397-4906-bcc9-1868a001a55c'}
Feb 16 00:50:11 silver xapi: [ info|silver|12944|sm_exec 
D:0013e8cabfd9|xapi] Session.destroy 
trackid=8444eb00454659e70ba6a9c1caa81f5b
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|10||scheduler] 
Scheduler sleep until 1424044234 (another 22 seconds)
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] TASK.signal 830 = ["Pending", 0.750000]
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] Performing: ["VIF_set_active", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "0"], true]
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] VIF.set_active 
346f48e4-5d8c-1d72-487a-c33565175be7.0 true
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] VIF_DB.signal 
346f48e4-5d8c-1d72-487a-c33565175be7.0
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] TASK.signal 830 = ["Pending", 0.875000]
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] Performing: 
["VM_set_domain_action_request", 
["346f48e4-5d8c-1d72-487a-c33565175be7", []]]
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] VM.set_domain_action_request 
346f48e4-5d8c-1d72-487a-c33565175be7 None
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] TASK.signal 830 = ["Pending", 1.000000]
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|xenops_server] VM_DB.signal 
346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|11|Async.VM.start 
R:17052e888f20|task_server] Task 830 completed; duration = 8
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|11||xenops_server] TASK.signal 830 = ["Completed", 
{"duration": 8.132588}]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Task", "830"]
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|16||xenops_server] Queue.pop returned ["Atomic", 
["VM_unpause", "346f48e4-5d8c-1d72-487a-c33565175be7"]]
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|16|Async.VM.start 
R:17052e888f20|xenops_server] Task 831 reference Async.VM.start 
R:17052e888f20: ["Atomic", ["VM_unpause", 
"346f48e4-5d8c-1d72-487a-c33565175be7"]]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenops event on Task 830
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|16|Async.VM.start 
R:17052e888f20|xenops_server] VM.unpause 
346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|16|Async.VM.start 
R:17052e888f20|xenops_server] VM_DB.signal 
346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xenopsd-xenlight: [debug|silver|16|Async.VM.start 
R:17052e888f20|task_server] Task 831 completed; duration = 0
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|16||xenops_server] TASK.signal 831 = ["Completed", 
{"duration": 0.000894}]
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|12||xenops_server] Queue.pop returned ["VM_check_state", 
"346f48e4-5d8c-1d72-487a-c33565175be7"]
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|12|events|xenops_server] Task 844 reference events: 
["VM_check_state", "346f48e4-5d8c-1d72-487a-c33565175be7"]
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|12|events|xenops_server] VM 
346f48e4-5d8c-1d72-487a-c33565175be7 is not requesting any attention
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|12|events|xenops_server] VM_DB.signal 
346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|12|events|task_server] Task 844 completed; duration = 0
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|12||xenops_server] TASK.signal 844 (object deleted)
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|15||xenops_server] Queue.pop returned ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvda"]]
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|15|events|xenops_server] Task 848 reference events: 
["VBD_check_state", ["346f48e4-5d8c-1d72-487a-c33565175be7", "xvda"]]
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|15|events|xenops_server] VBD.check_state 
346f48e4-5d8c-1d72-487a-c33565175be7.xvda
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Vif", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "0"]]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] ignoring xenops event on VIF 
346f48e4-5d8c-1d72-487a-c33565175be7.0
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Task", "830"]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenops event on Task 830
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Vm", 
"346f48e4-5d8c-1d72-487a-c33565175be7"]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] ignoring xenops event on VM 
346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Task", "831"]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenops event on Task 831
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Vm", 
"346f48e4-5d8c-1d72-487a-c33565175be7"]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] ignoring xenops event on VM 
346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|15|events|hotplug] Checking to see whether 
/local/domain/0/backend/vbd/13/51712/hotplug-status
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|15|events|xenops_server] VBD_DB.signal 
346f48e4-5d8c-1d72-487a-c33565175be7.xvda
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|15|events|task_server] Task 848 completed; duration = 0
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|15||xenops_server] TASK.signal 848 (object deleted)
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|11||xenops_server] Queue.pop returned ["VBD_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvdb"]]
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|11|events|xenops_server] Task 850 reference events: 
["VBD_check_state", ["346f48e4-5d8c-1d72-487a-c33565175be7", "xvdb"]]
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|11|events|xenops_server] VBD.check_state 
346f48e4-5d8c-1d72-487a-c33565175be7.xvdb
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Vbd", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvda"]]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] ignoring xenops event on VBD 
346f48e4-5d8c-1d72-487a-c33565175be7.xvda
Feb 16 00:50:11 silver xapi: [error|silver|12864|Async.VM.start 
R:17052e888f20|sql] Duplicate key in set or map: table task; field 
other_config; ref OpaqueRef:17052e88-8f20-827e-f456-8e0c35a250c0; key 
debug_info:cancel_points_seen
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|xapi] Raised at file \"db_cache_impl.ml\", line 251, 
characters 11-51\nCalled from file \"lib/pervasiveext.ml\", line 22, 
characters 2-9\n
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|xenops] Failed to add debug_info:cancel_points_seen = 1 
to task OpaqueRef:17052e88-8f20-827e-f456-8e0c35a250c0: 
Db_exn.Duplicate_key("task", "other_config", 
"OpaqueRef:17052e88-8f20-827e-f456-8e0c35a250c0", 
"debug_info:cancel_points_seen")
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|xenops] re-enabled xenops events on VM: 
346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|xenops] VM 346f48e4-5d8c-1d72-487a-c33565175be7 
set_resident_on
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|mscgen] xapi=>xapi [label="session.slave_login"];
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|11|events|hotplug] Checking to see whether 
/local/domain/0/backend/vbd/13/51728/hotplug-status
Feb 16 00:50:11 silver xapi: [debug|silver|12947 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.slave_login 
D:71585d3067d8 created by task R:17052e888f20
Feb 16 00:50:11 silver xapi: [ info|silver|12947 UNIX 
/var/lib/xcp/xapi|session.slave_login D:d1145e92c10c|xapi] 
Session.create trackid=634c950964f29fd9eb723025c069d739 pool=true uname= 
originator= is_local_superuser=true auth_user_sid= 
parent=trackid=9834f5af41c964e225f24279aefe4e49
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|11|events|xenops_server] VBD_DB.signal 
346f48e4-5d8c-1d72-487a-c33565175be7.xvdb
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|11|events|task_server] Task 850 completed; duration = 0
Feb 16 00:50:11 silver xapi: [debug|silver|12947 UNIX 
/var/lib/xcp/xapi|session.slave_login D:d1145e92c10c|mscgen] xapi=>xapi 
[label="session.get_uuid"];
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|11||xenops_server] TASK.signal 850 (object deleted)
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|16||xenops_server] Queue.pop returned ["VIF_check_state", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "0"]]
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|16|events|xenops_server] Task 853 reference events: 
["VIF_check_state", ["346f48e4-5d8c-1d72-487a-c33565175be7", "0"]]
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|16|events|xenops_server] VIF.check_state 
346f48e4-5d8c-1d72-487a-c33565175be7.0
Feb 16 00:50:11 silver xapi: [debug|silver|12948 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.get_uuid 
D:8e0c5351db93 created by task D:d1145e92c10c
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Vbd", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvdb"]]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenops event on VBD 
346f48e4-5d8c-1d72-487a-c33565175be7.xvdb
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenopsd event: ignoring event for VBD (VM 
346f48e4-5d8c-1d72-487a-c33565175be7 not resident)
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|mscgen] xapi=>xapi [label="VM.atomic_set_resident_on"];
Feb 16 00:50:11 silver xapi: [debug|silver|12949 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task 
dispatch:VM.atomic_set_resident_on D:1d20d73e7363 created by task 
R:17052e888f20
Feb 16 00:50:11 silver xapi: [ info|silver|12949 UNIX 
/var/lib/xcp/xapi|dispatch:VM.atomic_set_resident_on 
D:1d20d73e7363|taskhelper] task VM.atomic_set_resident_on R:8dce9f6b57e5 
(uuid:f4c222cc-0647-f296-9be0-0ddd965c05a7) created 
(trackid=634c950964f29fd9eb723025c069d739) by task R:17052e888f20
Feb 16 00:50:11 silver xapi: [debug|silver|12949 UNIX 
/var/lib/xcp/xapi|VM.atomic_set_resident_on R:8dce9f6b57e5|audit] 
VM.atomic_set_resident_on: VM = '346f48e4-5d8c-1d72-487a-c33565175be7 
(ffsSR)'
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|16|events|hotplug] Checking to see whether 
/xapi/346f48e4-5d8c-1d72-487a-c33565175be7/hotplug/13/vif/0/hotplug
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|16|events|task_server] Task 853 completed; duration = 0
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|16||xenops_server] TASK.signal 853 (object deleted)
Feb 16 00:50:11 silver xapi: [20150215T23:50:11.678Z|audit|silver|12949 
UNIX /var/lib/xcp/xapi|VM.atomic_set_resident_on R:8dce9f6b57e5|audit] 
('trackid=634c950964f29fd9eb723025c069d739' 'LOCAL_SUPERUSER' 
'OpaqueRef:0d0d7bf7-4d03-afc4-4280-8724014224ba' 'ALLOWED' 'OK' 'API' 
'VM.atomic_set_resident_on' (('vm' 'ffsSR' 
'346f48e4-5d8c-1d72-487a-c33565175be7' 
'OpaqueRef:72c4eca8-fb53-ac9c-57f4-6b22090b05ac') ('host' 'silver' 
'0d83e699-df0b-40db-9934-b5cbc9e5eafe' 
'OpaqueRef:0d0d7bf7-4d03-afc4-4280-8724014224ba')))
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|mscgen] xapi=>xapi [label="session.logout"];
Feb 16 00:50:11 silver xapi: [debug|silver|12950 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.logout 
D:45ee67ff6e2a created by task R:17052e888f20
Feb 16 00:50:11 silver xapi: [ info|silver|12950 UNIX 
/var/lib/xcp/xapi|session.logout D:439dd86f2548|xapi] Session.destroy 
trackid=634c950964f29fd9eb723025c069d739
Feb 16 00:50:11 silver xapi: [ info|silver|12864|Async.VM.start 
R:17052e888f20|xenops] xenops: UPDATES.refresh_vm 
346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|1992|Async.VM.start R:17052e888f20|xenops_server] 
UPDATES.refresh_vm 346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|1992|Async.VM.start R:17052e888f20|xenops_server] 
VM_DB.signal 346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|1992|Async.VM.start R:17052e888f20|xenops_server] 
VBD_DB.signal 346f48e4-5d8c-1d72-487a-c33565175be7.xvdb
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|1992|Async.VM.start R:17052e888f20|xenops_server] 
VBD_DB.signal 346f48e4-5d8c-1d72-487a-c33565175be7.xvda
Feb 16 00:50:11 silver xenopsd-xenlight: 
[debug|silver|1992|Async.VM.start R:17052e888f20|xenops_server] 
VIF_DB.signal 346f48e4-5d8c-1d72-487a-c33565175be7.0
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Vm", 
"346f48e4-5d8c-1d72-487a-c33565175be7"]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenops event on VM 
346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver rsyslogd-2177: imuxsock[pid 3319]: begin to drop 
messages due to rate-limiting
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|xenops] Client.UPDATES.inject_barrier 87
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenopsd event: processing event for VM 
346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Will update VM.allowed_operations because 
power_state has changed.
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenopsd event: Updating VM 
346f48e4-5d8c-1d72-487a-c33565175be7 power_state <- Running
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Will update VM.allowed_operations because domid 
has changed.
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenopsd event: Updating VM 
346f48e4-5d8c-1d72-487a-c33565175be7 domid
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenopsd event: Updating VM 
346f48e4-5d8c-1d72-487a-c33565175be7 consoles
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenopsd event: Updating VM 
346f48e4-5d8c-1d72-487a-c33565175be7 memory_target <- 536870912
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenopsd event: VM 
346f48e4-5d8c-1d72-487a-c33565175be7 domid 13 
uncooperative_balloon_driver = false
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenopsd event: Updating VM 
346f48e4-5d8c-1d72-487a-c33565175be7 domid 13 guest_agent
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenopsd event: Updating VM 
346f48e4-5d8c-1d72-487a-c33565175be7 domid 13 xsdata
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenopsd event: Updating VM 
346f48e4-5d8c-1d72-487a-c33565175be7 domid 13 memory target
Feb 16 00:50:11 silver xcp-rrdd: [debug|silver|60 unix_rpc||http] 
Request { frame = false; method = POST; uri = /var/lib/xcp/xcp-rrdd; 
query = [  ]; content_length = [ 270 ]; transfer encoding = ; version = 
1.1; cookie = [ = ]; task = ; subtask_of = ; content-type = ; host = ; 
user_agent = /usr/sbin/xapi }
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenopsd event: Updating VM 
346f48e4-5d8c-1d72-487a-c33565175be7 vcpu_target <- 1
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenopsd event: Updating VM 
346f48e4-5d8c-1d72-487a-c33565175be7 last_start_time <- 20150215T23:50:03Z
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenopsd event: Updating VM 
346f48e4-5d8c-1d72-487a-c33565175be7 shadow_multiplier <- 1.00
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|mscgen] xapi=>xapi [label="session.slave_login"];
Feb 16 00:50:11 silver xapi: [debug|silver|12951 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.slave_login 
D:3229c9bc2b58 created by task D:14088ced0b11
Feb 16 00:50:11 silver xapi: [ info|silver|12951 UNIX 
/var/lib/xcp/xapi|session.slave_login D:bcb8c8bb5d55|xapi] 
Session.create trackid=1a4981d1dc22539401bb4e47c339f3bb pool=true uname= 
originator= is_local_superuser=true auth_user_sid= 
parent=trackid=9834f5af41c964e225f24279aefe4e49
Feb 16 00:50:11 silver xapi: [debug|silver|12951 UNIX 
/var/lib/xcp/xapi|session.slave_login D:bcb8c8bb5d55|mscgen] xapi=>xapi 
[label="session.get_uuid"];
Feb 16 00:50:11 silver xapi: [debug|silver|12952 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.get_uuid 
D:b454d536f92c created by task D:bcb8c8bb5d55
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|mscgen] xapi=>xapi [label="VM.update_allowed_operations"];
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task 
dispatch:VM.update_allowed_operations D:aec019001299 created by task 
D:14088ced0b11
Feb 16 00:50:11 silver xapi: [ info|silver|12953 UNIX 
/var/lib/xcp/xapi|dispatch:VM.update_allowed_operations 
D:aec019001299|taskhelper] task VM.update_allowed_operations 
R:2fcb5d41c3a2 (uuid:98b22545-5e0a-8863-b457-6125ec8ea419) created 
(trackid=1a4981d1dc22539401bb4e47c339f3bb) by task D:14088ced0b11
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|audit] 
VM.update_allowed_operations: VM = '346f48e4-5d8c-1d72-487a-c33565175be7 
(ffsSR)'
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|smint] 
SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: [debug|silver|12953 UNIX 
/var/lib/xcp/xapi|VM.update_allowed_operations R:2fcb5d41c3a2|xapi] No 
operations are valid because current-operations = [ 
OpaqueRef:17052e88-8f20-827e-f456-8e0c35a250c0 -> attach ]
Feb 16 00:50:11 silver xapi: [20150215T23:50:11.725Z|audit|silver|12953 
UNIX /var/lib/xcp/xapi|VM.update_allowed_operations 
R:2fcb5d41c3a2|audit] ('trackid=1a4981d1dc22539401bb4e47c339f3bb' 
'LOCAL_SUPERUSER' 'OpaqueRef:0d0d7bf7-4d03-afc4-4280-8724014224ba' 
'ALLOWED' 'OK' 'API' 'VM.update_allowed_operations' (('self' 'ffsSR' 
'346f48e4-5d8c-1d72-487a-c33565175be7' 
'OpaqueRef:72c4eca8-fb53-ac9c-57f4-6b22090b05ac')))
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|mscgen] xapi=>xapi [label="session.logout"];
Feb 16 00:50:11 silver xapi: [debug|silver|12954 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.logout 
D:aabb96503f86 created by task D:14088ced0b11
Feb 16 00:50:11 silver xapi: [ info|silver|12954 UNIX 
/var/lib/xcp/xapi|session.logout D:39491c63a3b6|xapi] Session.destroy 
trackid=1a4981d1dc22539401bb4e47c339f3bb
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing barrier 87
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Vbd", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvdb"]]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenops event on VBD 
346f48e4-5d8c-1d72-487a-c33565175be7.xvdb
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] VM 346f48e4-5d8c-1d72-487a-c33565175be7 VBD 
userdevices = [ xvdb; xvda ]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenopsd event: Updating VBD 
346f48e4-5d8c-1d72-487a-c33565175be7.xvdb device <- xvdb; 
currently_attached <- true
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] VBD 346f48e4-5d8c-1d72-487a-c33565175be7.xvdb 
backend_present = 
0e141376-6525-ff18-ffee-862446f5a617/ubuntu-14.04.1-server-amd64.iso
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Vbd", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvda"]]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenops event on VBD 
346f48e4-5d8c-1d72-487a-c33565175be7.xvda
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] VM 346f48e4-5d8c-1d72-487a-c33565175be7 VBD 
userdevices = [ xvdb; xvda ]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenopsd event: Updating VBD 
346f48e4-5d8c-1d72-487a-c33565175be7.xvda device <- xvda; 
currently_attached <- true
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] VBD 346f48e4-5d8c-1d72-487a-c33565175be7.xvda 
backend_present = 13d626f8-4a8b-e822-f821-de35f23d2886/manual
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Vif", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "0"]]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenops event on VIF 
346f48e4-5d8c-1d72-487a-c33565175be7.0
Feb 16 00:50:11 silver xcp-networkd: [ 
info|silver|426|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|network_utils] /sbin/ip link show dev vif13.0
Feb 16 00:50:11 silver xcp-networkd: [ 
info|silver|426|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|network_utils] Looking for mtu in [46: vif13.0: 
<NO-CARRIER,BROADCAST,NOARP,UP> mtu 1500 qdisc pfifo_fast master xapi0 
state DOWN mode DEFAULT group default qlen 32#012 link/ether 
fe:ff:ff:ff:ff:ff brd ff:ff:ff:ff:ff:ff#012]
Feb 16 00:50:11 silver xcp-networkd: [ 
info|silver|426|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|network_utils] Found at [ 3 ]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] xenopsd event: Updating VIF 
346f48e4-5d8c-1d72-487a-c33565175be7.0 currently_attached <- true
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events D:14088ced0b11|xapi] 
No operations are valid because current-operations = [ 
OpaqueRef:17052e88-8f20-827e-f456-8e0c35a250c0 -> attach ]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Vbd", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvdb"]]
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|xenops] Signalling xenapi event thread to re-register
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Skipping (already processed this round)
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Vbd", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "xvda"]]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Skipping (already processed this round)
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Processing event: ["Vif", 
["346f48e4-5d8c-1d72-487a-c33565175be7", "0"]]
Feb 16 00:50:11 silver xapi: 
[debug|silver|86|org.xen.xcp.xenops.xenlight events 
D:14088ced0b11|xenops] Skipping (already processed this round)
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|xenops] triggering xapi event thread to re-register via 
session.logout
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|mscgen] xapi=>xapi [label="session.logout"];
Feb 16 00:50:11 silver xapi: [debug|silver|12955 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.logout 
D:ce32fb44f426 created by task D:450b74c73386
Feb 16 00:50:11 silver xapi: [ info|silver|12955 UNIX 
/var/lib/xcp/xapi|session.logout D:b8f86c308b43|xapi] Session.destroy 
trackid=1528eee39bec4339e0e907e0ec3aa947
Feb 16 00:50:11 silver xapi: [ info|silver|12861 UNIX 
/var/lib/xcp/xapi|event.from D:312f8e29eade|xapi_event] 
trackid=1528eee39bec4339e0e907e0ec3aa947 raising SESSION_INVALID 
*because* subscription is invalid
Feb 16 00:50:11 silver xapi: [debug|silver|12861 UNIX 
/var/lib/xcp/xapi|event.from D:312f8e29eade|xapi] Raised at file 
\"xapi_event.ml\", line 338, characters 9-94\nCalled from file 
\"xapi_event.ml\", line 447, characters 6-29\nCalled from file 
\"lib/pervasiveext.ml\", line 22, characters 2-9\n
Feb 16 00:50:11 silver xapi: [debug|silver|12861 UNIX 
/var/lib/xcp/xapi|event.from D:312f8e29eade|backtrace] Raised at file 
\"xapi_event.ml\", line 338, characters 9-94\nCalled from file 
\"xapi_event.ml\", line 447, characters 6-29\nCalled from file 
\"lib/pervasiveext.ml\", line 22, characters 2-9\nRe-raised at file 
\"lib/pervasiveext.ml\", line 26, characters 22-25\nCalled from file 
\"xapi_event.ml\", line 439, characters 2-711\nCalled from file 
\"xapi_event.ml\", line 517, characters 19-73\nCalled from file 
\"rbac.ml\", line 227, characters 16-23\nRe-raised at file \"rbac.ml\", 
line 236, characters 10-15\nCalled from file \"server_helpers.ml\", line 
75, characters 11-41\n
Feb 16 00:50:11 silver xapi: [debug|silver|12861 UNIX 
/var/lib/xcp/xapi|event.from D:312f8e29eade|dispatcher] 
Server_helpers.exec exception_handler: Got exception SESSION_INVALID: [ 
OpaqueRef:2a2fb147-823f-0849-f7a2-bd40d966882f ]
Feb 16 00:50:11 silver xapi: [debug|silver|12861 UNIX 
/var/lib/xcp/xapi|event.from D:312f8e29eade|dispatcher] Raised at file 
\"xapi_event.ml\", line 338, characters 9-94\nCalled from file 
\"xapi_event.ml\", line 447, characters 6-29\nCalled from file 
\"lib/pervasiveext.ml\", line 22, characters 2-9\nRe-raised at file 
\"lib/pervasiveext.ml\", line 26, characters 22-25\nCalled from file 
\"xapi_event.ml\", line 439, characters 2-711\nCalled from file 
\"xapi_event.ml\", line 517, characters 19-73\nCalled from file 
\"rbac.ml\", line 227, characters 16-23\nRe-raised at file \"rbac.ml\", 
line 236, characters 10-15\nCalled from file \"server_helpers.ml\", line 
75, characters 11-41\n
Feb 16 00:50:11 silver xapi: [debug|silver|12861 UNIX 
/var/lib/xcp/xapi|event.from D:312f8e29eade|backtrace] Raised at file 
\"xapi_event.ml\", line 338, characters 9-94\nCalled from file 
\"xapi_event.ml\", line 447, characters 6-29\nCalled from file 
\"lib/pervasiveext.ml\", line 22, characters 2-9\nRe-raised at file 
\"lib/pervasiveext.ml\", line 26, characters 22-25\nCalled from file 
\"xapi_event.ml\", line 439, characters 2-711\nCalled from file 
\"xapi_event.ml\", line 517, characters 19-73\nCalled from file 
\"rbac.ml\", line 227, characters 16-23\nRe-raised at file \"rbac.ml\", 
line 236, characters 10-15\nCalled from file \"server_helpers.ml\", line 
75, characters 11-41\n
Feb 16 00:50:11 silver xapi: [debug|silver|12861 UNIX 
/var/lib/xcp/xapi|event.from D:312f8e29eade|xapi] Raised at file 
\"xapi_event.ml\", line 338, characters 9-94\nCalled from file 
\"xapi_event.ml\", line 447, characters 6-29\nCalled from file 
\"lib/pervasiveext.ml\", line 22, characters 2-9\nRe-raised at file 
\"lib/pervasiveext.ml\", line 26, characters 22-25\nCalled from file 
\"xapi_event.ml\", line 439, characters 2-711\nCalled from file 
\"xapi_event.ml\", line 517, characters 19-73\nCalled from file 
\"rbac.ml\", line 227, characters 16-23\nRe-raised at file \"rbac.ml\", 
line 236, characters 10-15\nCalled from file \"server_helpers.ml\", line 
75, characters 11-41\nRe-raised at file \"server_helpers.ml\", line 90, 
characters 14-15\nCalled from file \"lib/pervasiveext.ml\", line 22, 
characters 2-9\n
Feb 16 00:50:11 silver xapi: [debug|silver|12861 UNIX 
/var/lib/xcp/xapi|dispatch:event.from D:af5f7b5bff30|xapi] Raised at 
file \"xapi_event.ml\", line 338, characters 9-94\nCalled from file 
\"xapi_event.ml\", line 447, characters 6-29\nCalled from file 
\"lib/pervasiveext.ml\", line 22, characters 2-9\nRe-raised at file 
\"lib/pervasiveext.ml\", line 26, characters 22-25\nCalled from file 
\"xapi_event.ml\", line 439, characters 2-711\nCalled from file 
\"xapi_event.ml\", line 517, characters 19-73\nCalled from file 
\"rbac.ml\", line 227, characters 16-23\nRe-raised at file \"rbac.ml\", 
line 236, characters 10-15\nCalled from file \"server_helpers.ml\", line 
75, characters 11-41\nRe-raised at file \"server_helpers.ml\", line 90, 
characters 14-15\nCalled from file \"lib/pervasiveext.ml\", line 22, 
characters 2-9\nRe-raised at file \"lib/pervasiveext.ml\", line 26, 
characters 22-25\nCalled from file \"lib/debug.ml\", line 57, characters 
17-20\nRe-raised at file \"lib/debug.ml\", line 62, characters 
10-11\nCalled from file \"lib/pervasiveext.ml\", line 22, characters 2-9\n
Feb 16 00:50:11 silver xapi: [debug|silver|12861 UNIX 
/var/lib/xcp/xapi|dispatch:event.from D:af5f7b5bff30|backtrace] Raised 
at file \"xapi_event.ml\", line 338, characters 9-94\nCalled from file 
\"xapi_event.ml\", line 447, characters 6-29\nCalled from file 
\"lib/pervasiveext.ml\", line 22, characters 2-9\nRe-raised at file 
\"lib/pervasiveext.ml\", line 26, characters 22-25\nCalled from file 
\"xapi_event.ml\", line 439, characters 2-711\nCalled from file 
\"xapi_event.ml\", line 517, characters 19-73\nCalled from file 
\"rbac.ml\", line 227, characters 16-23\nRe-raised at file \"rbac.ml\", 
line 236, characters 10-15\nCalled from file \"server_helpers.ml\", line 
75, characters 11-41\nRe-raised at file \"server_helpers.ml\", line 90, 
characters 14-15\nCalled from file \"lib/pervasiveext.ml\", line 22, 
characters 2-9\nRe-raised at file \"lib/pervasiveext.ml\", line 26, 
characters 22-25\nCalled from file \"lib/debug.ml\", line 57, characters 
17-20\nRe-raised at file \"lib/debug.ml\", line 62, characters 
10-11\nCalled from file \"lib/pervasiveext.ml\", line 22, characters 
2-9\nRe-raised at file \"lib/pervasiveext.ml\", line 26, characters 
22-25\nCalled from file \"server_helpers.ml\", line 136, characters 
10-106\nCalled from file \"server.ml\", line 1943, characters 
23-161\nCalled from file \"server_helpers.ml\", line 115, characters 4-7\n
Feb 16 00:50:11 silver xapi: [debug|silver|87|xapi events 
D:450b74c73386|xapi] Raised at file \"client.ml\", line 6, characters 
37-75\nCalled from file \"client.ml\", line 18, characters 
55-110\nCalled from file \"client.ml\", line 3136, characters 
6-74\nCalled from file \"xapi_xenops.ml\", line 1654, characters 
19-89\nCalled from file \"lib/pervasiveext.ml\", line 22, characters 2-9\n
Feb 16 00:50:11 silver xapi: [debug|silver|87|xapi events 
D:450b74c73386|mscgen] xapi=>xapi [label="session.logout"];
Feb 16 00:50:11 silver xapi: [debug|silver|12956 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.logout 
D:5875e5f7660d created by task D:450b74c73386
Feb 16 00:50:11 silver xapi: [debug|silver|12956 UNIX 
/var/lib/xcp/xapi|session_check D:4b8c32aac620|xapi] Session check 
failed: missing reference; tbl = session, ref = 
OpaqueRef:2a2fb147-823f-0849-f7a2-bd40d966882f
Feb 16 00:50:11 silver xapi: [debug|silver|12956 UNIX 
/var/lib/xcp/xapi|session_check D:4b8c32aac620|backtrace] Raised at file 
\"session_check.ml\", line 53, characters 13-79\nCalled from file 
\"server_helpers.ml\", line 72, characters 11-23\n
Feb 16 00:50:11 silver xapi: [debug|silver|12956 UNIX 
/var/lib/xcp/xapi|session_check D:4b8c32aac620|dispatcher] 
Server_helpers.exec exception_handler: Got exception SESSION_INVALID: [ 
OpaqueRef:2a2fb147-823f-0849-f7a2-bd40d966882f ]
Feb 16 00:50:11 silver xapi: [debug|silver|12956 UNIX 
/var/lib/xcp/xapi|session_check D:4b8c32aac620|dispatcher] Raised at 
file \"session_check.ml\", line 53, characters 13-79\nCalled from file 
\"server_helpers.ml\", line 72, characters 11-23\n
Feb 16 00:50:11 silver xapi: [debug|silver|12956 UNIX 
/var/lib/xcp/xapi|session_check D:4b8c32aac620|backtrace] Raised at file 
\"session_check.ml\", line 53, characters 13-79\nCalled from file 
\"server_helpers.ml\", line 72, characters 11-23\n
Feb 16 00:50:11 silver xapi: [debug|silver|12956 UNIX 
/var/lib/xcp/xapi|session_check D:4b8c32aac620|xapi] Raised at file 
\"session_check.ml\", line 53, characters 13-79\nCalled from file 
\"server_helpers.ml\", line 72, characters 11-23\nRe-raised at file 
\"server_helpers.ml\", line 90, characters 14-15\nCalled from file 
\"lib/pervasiveext.ml\", line 22, characters 2-9\n
Feb 16 00:50:11 silver xapi: [debug|silver|12956 UNIX 
/var/lib/xcp/xapi|dispatch:session.logout D:5875e5f7660d|xapi] Raised at 
file \"session_check.ml\", line 53, characters 13-79\nCalled from file 
\"server_helpers.ml\", line 72, characters 11-23\nRe-raised at file 
\"server_helpers.ml\", line 90, characters 14-15\nCalled from file 
\"lib/pervasiveext.ml\", line 22, characters 2-9\nRe-raised at file 
\"lib/pervasiveext.ml\", line 26, characters 22-25\nCalled from file 
\"lib/debug.ml\", line 57, characters 17-20\nRe-raised at file 
\"lib/debug.ml\", line 62, characters 10-11\nCalled from file 
\"lib/pervasiveext.ml\", line 22, characters 2-9\n
Feb 16 00:50:11 silver xapi: [debug|silver|12956 UNIX 
/var/lib/xcp/xapi|dispatch:session.logout D:5875e5f7660d|backtrace] 
Raised at file \"session_check.ml\", line 53, characters 13-79\nCalled 
from file \"server_helpers.ml\", line 72, characters 11-23\nRe-raised at 
file \"server_helpers.ml\", line 90, characters 14-15\nCalled from file 
\"lib/pervasiveext.ml\", line 22, characters 2-9\nRe-raised at file 
\"lib/pervasiveext.ml\", line 26, characters 22-25\nCalled from file 
\"lib/debug.ml\", line 57, characters 17-20\nRe-raised at file 
\"lib/debug.ml\", line 62, characters 10-11\nCalled from file 
\"lib/pervasiveext.ml\", line 22, characters 2-9\nRe-raised at file 
\"lib/pervasiveext.ml\", line 26, characters 22-25\nCalled from file 
\"server.ml\", line 471, characters 12-48\nCalled from file 
\"server_helpers.ml\", line 115, characters 4-7\n
Feb 16 00:50:11 silver xapi: [debug|silver|87|xapi events 
D:450b74c73386|xenops] Woken event thread: updating list of event 
subscriptions
Feb 16 00:50:11 silver xapi: [debug|silver|87|xapi events 
D:450b74c73386|mscgen] xapi=>xapi [label="session.slave_login"];
Feb 16 00:50:11 silver xapi: [debug|silver|12957 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.slave_login 
D:9e8204414c04 created by task D:450b74c73386
Feb 16 00:50:11 silver xapi: [error|silver|12864|Async.VM.start 
R:17052e888f20|xenops] Not_found
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|xenops] Could not parse weight value. Setting it to 
default value 256.
Feb 16 00:50:11 silver xapi: [ info|silver|12957 UNIX 
/var/lib/xcp/xapi|session.slave_login D:d0b845451123|xapi] 
Session.create trackid=f2e5f6e63a2ee0051e4bc45448890a65 pool=true uname= 
originator= is_local_superuser=true auth_user_sid= 
parent=trackid=9834f5af41c964e225f24279aefe4e49
Feb 16 00:50:11 silver xapi: [error|silver|12864|Async.VM.start 
R:17052e888f20|xenops] Not_found
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|xenops] Could not parse cap value. Setting it to default 
value 0.
Feb 16 00:50:11 silver xapi: [debug|silver|12957 UNIX 
/var/lib/xcp/xapi|session.slave_login D:d0b845451123|mscgen] xapi=>xapi 
[label="session.get_uuid"];
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|xenops] VM 346f48e4-5d8c-1d72-487a-c33565175be7 metadata 
has changed: updating xenopsd
Feb 16 00:50:11 silver xapi: [ info|silver|12864|Async.VM.start 
R:17052e888f20|xenops] xenops: VM.import_metadata {"vm": {"id": 
"346f48e4-5d8c-1d72-487a-c33565175be7", "name": "ffsSR", "ssidref": 0, 
"xsdata": {"vm-data": ""}, "platformdata": {"generation-id": 
"510944606515534931:8047228083764823657", "timeoffset": "0", "usb": 
"true", "usb_tablet": "true", "nx": "true", "acpi": "1", "apic": "true", 
"pae": "true", "viridian": "true"}, "bios_strings": {"bios-vendor": 
"Xen", "bios-version": "", "system-manufacturer": "Xen", 
"system-product-name": "HVM domU", "system-version": "", 
"system-serial-number": "", "hp-rombios": "", "oem-1": "Xen", "oem-2": 
"MS_VM_CERT\/SHA1\/bdbeb6e0a816d43fa6d3fe8aaef04c2bad9d3e3d"}, "ty": 
["PV", {"boot": ["Indirect", {"bootloader": "pygrub", "extra_args": 
"ip=10.99.99.9::10.99.99.1:255.255.255.0:trusty dns0=109.95.202.2 
ns=109.95.202.2 noipv6 ks=http:\/\/10.99.99.1:1080\/xen.ks 
ksdevice=eth0", "legacy_args": "", "bootloader_args": "", "devices": 
[["VDI", 
"0e141376-6525-ff18-ffee-862446f5a617\/ubuntu-14.04.1-server-amd64.iso"]]}], 
"framebuffer": false, "vncterm": true}], 
"suppress_spurious_page_faults": false, "memory_static_max": 536870912, 
"memory_dynamic_max": 536870912, "memory_dynamic_min": 536870912, 
"vcpu_max": 1, "vcpus": 1, "scheduler_params": {"priority": [256, 0], 
"affinity": []}, "on_crash": ["Start"], "on_shutdown": ["Shutdown"], 
"on_reboot": ["Start"], "pci_msitranslate": true, "pci_power_mgmt": 
false}, "vbds": [{"id": ["346f48e4-5d8c-1d72-487a-c33565175be7", 
"xvda"], "position": ["Xen", 0, 0], "mode": "ReadWrite", "backend": 
["VDI", "13d626f8-4a8b-e822-f821-de35f23d2886\/manual"], "ty": "Disk", 
"unpluggable": true, "extra_backend_keys": {}, "extra_private_keys": 
{}}, {"id": ["346f48e4-5d8c-1d72-487a-c33565175be7", "xvdb"], 
"position": ["Xen", 1, 0], "mode": "ReadOnly", "backend": ["VDI", 
"0e141376-6525-ff18-ffee-862446f5a617\/ubuntu-14.04.1-server-amd64.iso"], "ty": 
"CDROM", "unpluggable": true, "extra_backend_keys": {}, 
"extra_private_keys": {}}], "vifs": [{"id": 
["346f48e4-5d8c-1d72-487a-c33565175be7", "0"], "position": 0, "mac": 
"7a:14:1b:59:3b:98", "carrier": true, "mtu": 1500, "backend": ["Local", 
"xapi0"], "other_config": {}, "locking_mode": "Unlocked", 
"extra_private_keys": {"vif-uuid": 
"3904a52a-dff7-12f0-ff31-704e65be5b01", "network-uuid": 
"405969c9-4c60-1aa4-6e5b-dad0c6f08ec5"}}], "pcis": []}
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|xenops] xapi_cache: updating cache for 
346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xapi: [debug|silver|12958 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.get_uuid 
D:17cbf08e4fef created by task D:d0b845451123
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|mscgen] xapi=>xapi [label="session.slave_login"];
Feb 16 00:50:11 silver xapi: [error|silver|87|xapi events 
D:450b74c73386|xenops] events_from_xapi: missing from the cache: [ 
4f1cbed7-eba5-4591-bc12-313612a9ecfe ]
Feb 16 00:50:11 silver xapi: [debug|silver|87|xapi events 
D:450b74c73386|mscgen] xapi=>xapi [label="event.from"];
Feb 16 00:50:11 silver xapi: [debug|silver|12959 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:event.from 
D:572dbb1aed7c created by task D:450b74c73386
Feb 16 00:50:11 silver xapi: [debug|silver|12960 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.slave_login 
D:345cf5ffc5ee created by task R:17052e888f20
Feb 16 00:50:11 silver xapi: [ info|silver|12960 UNIX 
/var/lib/xcp/xapi|session.slave_login D:1bb4b66b0936|xapi] 
Session.create trackid=54337b83bb0ae885c3cea778309a3387 pool=true uname= 
originator= is_local_superuser=true auth_user_sid= 
parent=trackid=9834f5af41c964e225f24279aefe4e49
Feb 16 00:50:11 silver xapi: [debug|silver|12960 UNIX 
/var/lib/xcp/xapi|session.slave_login D:1bb4b66b0936|mscgen] xapi=>xapi 
[label="session.get_uuid"];
Feb 16 00:50:11 silver xapi: [debug|silver|12961 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.get_uuid 
D:d19aecef60fe created by task D:1bb4b66b0936
Feb 16 00:50:11 silver xapi: [debug|silver|87|xapi events 
D:450b74c73386|xenops] Event on VM 346f48e4-5d8c-1d72-487a-c33565175be7; 
resident_here = true
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|mscgen] xapi=>xapi [label="event.inject"];
Feb 16 00:50:11 silver xapi: [debug|silver|12962 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:event.inject 
D:a46ec25d4356 created by task R:17052e888f20
Feb 16 00:50:11 silver xapi: [20150215T23:50:11.792Z|audit|silver|12962 
UNIX /var/lib/xcp/xapi|event.inject D:4a198f356336|audit] 
('trackid=54337b83bb0ae885c3cea778309a3387' 'LOCAL_SUPERUSER' 
'OpaqueRef:0d0d7bf7-4d03-afc4-4280-8724014224ba' 'ALLOWED' 'OK' 'API' 
'event.inject' (('_ref' 'ffsSR' '346f48e4-5d8c-1d72-487a-c33565175be7' 
'OpaqueRef:72c4eca8-fb53-ac9c-57f4-6b22090b05ac')))
Feb 16 00:50:11 silver xapi: [error|silver|87|xapi events 
D:450b74c73386|xenops] Not_found
Feb 16 00:50:11 silver xapi: [debug|silver|87|xapi events 
D:450b74c73386|xenops] Could not parse weight value. Setting it to 
default value 256.
Feb 16 00:50:11 silver xapi: [error|silver|87|xapi events 
D:450b74c73386|xenops] Not_found
Feb 16 00:50:11 silver xapi: [debug|silver|87|xapi events 
D:450b74c73386|xenops] Could not parse cap value. Setting it to default 
value 0.
Feb 16 00:50:11 silver xapi: [debug|silver|87|xapi events 
D:450b74c73386|mscgen] xapi=>xapi [label="event.from"];
Feb 16 00:50:11 silver xapi: [debug|silver|12963 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:event.from 
D:5c8be2e243a7 created by task D:450b74c73386
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|mscgen] xapi=>xapi [label="session.logout"];
Feb 16 00:50:11 silver xapi: [debug|silver|12964 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.logout 
D:caacc7495891 created by task R:17052e888f20
Feb 16 00:50:11 silver xapi: [ info|silver|12964 UNIX 
/var/lib/xcp/xapi|session.logout D:d67e6af2b519|xapi] Session.destroy 
trackid=54337b83bb0ae885c3cea778309a3387
Feb 16 00:50:11 silver xapi: [debug|silver|87|xapi events 
D:450b74c73386|xenops] Event on VM 346f48e4-5d8c-1d72-487a-c33565175be7; 
resident_here = true
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|xenops] Waiting for token greater than: 
00000000000000542022,00000000000000000000
Feb 16 00:50:11 silver xapi: [error|silver|87|xapi events 
D:450b74c73386|xenops] Not_found
Feb 16 00:50:11 silver xapi: [debug|silver|87|xapi events 
D:450b74c73386|xenops] Could not parse weight value. Setting it to 
default value 256.
Feb 16 00:50:11 silver xapi: [error|silver|87|xapi events 
D:450b74c73386|xenops] Not_found
Feb 16 00:50:11 silver xapi: [debug|silver|87|xapi events 
D:450b74c73386|xenops] Could not parse cap value. Setting it to default 
value 0.
Feb 16 00:50:11 silver xapi: [debug|silver|87|xapi events 
D:450b74c73386|mscgen] xapi=>xapi [label="event.from"];
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: [debug|silver|12965 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:event.from 
D:3724dc82916c created by task D:450b74c73386
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_ATTACH
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_DETACH
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|smint] SM.feature: unknown feature SR_CREATE
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|xapi] Message.create VM_STARTED 5 VM 
346f48e4-5d8c-1d72-487a-c33565175be7
Feb 16 00:50:11 silver xapi: [debug|silver|12864|Async.VM.start 
R:17052e888f20|thread_queue] push(email message queue, VM_STARTED): 
queue = [ VM_STARTED ](1)
Feb 16 00:50:11 silver xapi: [debug|silver|83||thread_queue] pop(email 
message queue) = VM_STARTED
Feb 16 00:50:11 silver xapi: [ info|silver|83||xapi] 
/usr/lib/xapi/mail-alarm not found, skipping
Feb 16 00:50:11 silver xapi: [debug|silver|83||thread_queue] email 
message queue: completed processing 1 items: queue = [  ](0)
Feb 16 00:50:11 silver xcp-rrdd: [debug|silver|61 unix_rpc||http] 
Request { frame = false; method = POST; uri = /var/lib/xcp/xcp-rrdd; 
query = [  ]; content_length = [ 399 ]; transfer encoding = ; version = 
1.1; cookie = [ = ]; task = ; subtask_of = ; content-type = ; host = ; 
user_agent = /usr/sbin/xapi }
Feb 16 00:50:11 silver xapi: [debug|silver|87|xapi events 
D:450b74c73386|xenops] Event on VM 346f48e4-5d8c-1d72-487a-c33565175be7; 
resident_here = true
Feb 16 00:50:11 silver xapi: 
[20150215T23:50:11.828Z|audit|silver|12864|Async.VM.start 
R:17052e888f20|audit] ('trackid=e5cf67662c9fdd46461a3f240d95012e' 
'LOCAL_SUPERUSER' 'root' 'ALLOWED' 'OK' 'API' 'VM.start' (('vm' 'ffsSR' 
'346f48e4-5d8c-1d72-487a-c33565175be7' 
'OpaqueRef:72c4eca8-fb53-ac9c-57f4-6b22090b05ac') ('start_paused' 
'B(false)' '' '') ('force' 'B(false)' '' '')))
Feb 16 00:50:11 silver xapi: [20150215T23:50:11.832Z|audit|silver|12862 
UNIX /var/lib/xcp/xapi|event.unregister D:0586477b9b24|audit] 
('trackid=e5cf67662c9fdd46461a3f240d95012e' 'LOCAL_SUPERUSER' 'root' 
'ALLOWED' 'OK' 'API' 'event.unregister' ())
Feb 16 00:50:11 silver xapi: [20150215T23:50:11.833Z|audit|silver|12862 
UNIX /var/lib/xcp/xapi|task.destroy D:def2d43a45c9|audit] 
('trackid=e5cf67662c9fdd46461a3f240d95012e' 'LOCAL_SUPERUSER' 'root' 
'ALLOWED' 'OK' 'API' 'task.destroy' (('self' 'Async.VM.start' 
'30475aa1-e5e9-0652-20e9-3a86fae21f52' 
'OpaqueRef:17052e88-8f20-827e-f456-8e0c35a250c0')))
Feb 16 00:50:11 silver xapi: [error|silver|87|xapi events 
D:450b74c73386|xenops] Not_found
Feb 16 00:50:11 silver xapi: [debug|silver|87|xapi events 
D:450b74c73386|xenops] Could not parse weight value. Setting it to 
default value 256.
Feb 16 00:50:11 silver xapi: [error|silver|87|xapi events 
D:450b74c73386|xenops] Not_found
Feb 16 00:50:11 silver xapi: [debug|silver|87|xapi events 
D:450b74c73386|xenops] Could not parse cap value. Setting it to default 
value 0.
Feb 16 00:50:11 silver xapi: [debug|silver|87|xapi events 
D:450b74c73386|mscgen] xapi=>xapi [label="event.from"];
Feb 16 00:50:11 silver xapi: [ info|silver|12862 UNIX 
/var/lib/xcp/xapi|session.logout D:5db9f948a64f|xapi] Session.destroy 
trackid=e5cf67662c9fdd46461a3f240d95012e
Feb 16 00:50:11 silver xapi: [debug|silver|12966 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:event.from 
D:90b972e9d08f created by task D:450b74c73386
Feb 16 00:50:11 silver kernel: [107536.983734] xen-blkback:ring-ref 8, 
event-channel 10, protocol 1 (x86_64-abi) persistent grants
Feb 16 00:50:11 silver kernel: [107536.986175] xen-blkback:ring-ref 9, 
event-channel 11, protocol 1 (x86_64-abi) persistent grants
Feb 16 00:50:12 silver kernel: [107538.067120] IPv6: 
ADDRCONF(NETDEV_CHANGE): vif13.0: link becomes ready
Feb 16 00:50:12 silver kernel: [107538.067134] xapi0: port 1(vif13.0) 
entered forwarding state
Feb 16 00:50:12 silver kernel: [107538.067142] xapi0: port 1(vif13.0) 
entered forwarding state

Regards,
Dawid

_______________________________________________
Xen-api mailing list
Xen-api@xxxxxxxxxxxxx
http://lists.xen.org/cgi-bin/mailman/listinfo/xen-api