[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

[Xen-API] ffsSR - xvda disk not visible


  • To: Xen API mailing list <xen-api@xxxxxxxxxxxxx>
  • From: Dawid Kowalski <dkadds2@xxxxxxxxx>
  • Date: Mon, 16 Feb 2015 00:53:08 +0100
  • Delivery-date: Sun, 15 Feb 2015 23:53:35 +0000
  • List-id: User and development list for XCP and XAPI <xen-api.lists.xen.org>

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


 


Rackspace

Lists.xenproject.org is hosted with RackSpace, monitoring our
servers 24x7x365 and backed by RackSpace's Fanatical Support®.