qemu-devel
[Top][All Lists]
Advanced

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

Re: [Qemu-devel] external snapshots freezes block device since qemu 2.8


From: Piotr Rybicki
Subject: Re: [Qemu-devel] external snapshots freezes block device since qemu 2.8
Date: Fri, 10 Mar 2017 16:44:26 +0100
User-agent: Mozilla/5.0 (Windows NT 10.0; WOW64; rv:45.0) Gecko/20100101 Thunderbird/45.8.0



W dniu 2017-03-10 o 15:49, Kashyap Chamarthy pisze:
On Thu, Mar 09, 2017 at 11:11:09AM +0100, Piotr Rybicki wrote:
Hello there.

I discovered, that since qemu 2.8 , external snapshots (very similar to:
http://wiki.libvirt.org/page/Live-disk-backup-with-active-blockcommit),
When I wrote this Wiki page, I tested it only with regular QCOW2 files
on EXT4 file system.
It used to work very well with raw files on gluster via fuse. I've tested with local storage - it acts the same.


freezes block device after:

# virsh blockcommit (...)

There is no error message after completion of the command above.
I'm using gluster + ZFS fuse mount as a storage for a VM on gentoo.
libvirt debug showed nothing helpful.
With qemu <2.8 -: snapshots are working as expected.

Is this a known issue?
Is it qemu or libvirt ?

If it helps, how can i diagnose this further?a
To see what libvirt is sending to QEMU, you can enable the debug log
filters, which can give some clue:

- In /etc/libvirt/libvirtd.conf, set these config attributes

     log_filters="1:libvirt 1:qemu 1:conf 1:security 3:event 3:json 3:file 3:object 
1:util"
     log_outputs="1:file:/var/log/libvirt/libvirtd.log"

- Restart libvirtd:

     $ systemctl restart libvirtd

- Perform your `blockcommit` test.

PS: A gentle reminder -- when reporting upstream, you'll likely better
help if you at least test with the latest releases (libvirt-3.1.0, and
QEMU 2.8), if not from Git.
Thanks for pinting this out.

I've tried several libvirt versions, including latest 3.1.0
Qemu 2.7 / 2.7.1 works fine, only issue is at qemu 2.8 (git version is not usable right now - it crashes before i can start blockcommit)

Command complete successfully, but qemu is locked when accessing it's disks. For example - one cannot ssh into vm.

libvirtd.log:

2017-03-10 15:04:26.069+0000: 16381: debug : virIdentitySetAttr:248 : ident=0x7f4e08001660 attribute=7 value=C=PL,O=InnerVision Sp. z o.o.,L=Warszawa,ST=Mazowieckie,CN=adm 2017-03-10 15:04:26.069+0000: 16381: debug : virThreadJobSet:96 : Thread 16381 (virNetServerHandleJob) is now running job remoteDispatchAuthList 2017-03-10 15:04:26.069+0000: 16381: debug : virThreadJobClear:121 : Thread 16381 (virNetServerHandleJob) finished job remoteDispatchAuthList with ret=0 2017-03-10 15:04:26.070+0000: 16379: debug : virThreadJobSet:96 : Thread 16379 (virNetServerHandleJob) is now running job remoteDispatchConnectSupportsFeature 2017-03-10 15:04:26.070+0000: 16379: debug : virThreadJobClear:121 : Thread 16379 (virNetServerHandleJob) finished job remoteDispatchConnectSupportsFeature with ret=0 2017-03-10 15:04:26.071+0000: 16378: debug : virThreadJobSet:96 : Thread 16378 (virNetServerHandleJob) is now running job remoteDispatchConnectOpen 2017-03-10 15:04:26.071+0000: 16378: debug : virConnectOpen:1169 : name=qemu:///system 2017-03-10 15:04:26.071+0000: 16378: debug : virConfLoadConfig:1604 : Loading config file '/etc/libvirt/libvirt.conf' 2017-03-10 15:04:26.071+0000: 16378: debug : virConfReadFile:778 : filename=/etc/libvirt/libvirt.conf 2017-03-10 15:04:26.071+0000: 16378: debug : virConfAddEntry:241 : Add entry (null) (nil) 2017-03-10 15:04:26.071+0000: 16378: debug : virConfAddEntry:241 : Add entry (null) (nil) 2017-03-10 15:04:26.071+0000: 16378: debug : virConfAddEntry:241 : Add entry (null) (nil) 2017-03-10 15:04:26.071+0000: 16378: debug : virConfAddEntry:241 : Add entry (null) (nil) 2017-03-10 15:04:26.071+0000: 16378: debug : virConfAddEntry:241 : Add entry (null) (nil) 2017-03-10 15:04:26.071+0000: 16378: debug : virConfAddEntry:241 : Add entry (null) (nil) 2017-03-10 15:04:26.071+0000: 16378: debug : virConfAddEntry:241 : Add entry (null) (nil) 2017-03-10 15:04:26.071+0000: 16378: debug : virConfAddEntry:241 : Add entry (null) (nil) 2017-03-10 15:04:26.071+0000: 16378: debug : virConfAddEntry:241 : Add entry (null) (nil) 2017-03-10 15:04:26.071+0000: 16378: debug : virConfAddEntry:241 : Add entry (null) (nil) 2017-03-10 15:04:26.071+0000: 16378: debug : virConfAddEntry:241 : Add entry (null) (nil) 2017-03-10 15:04:26.071+0000: 16378: debug : virConfAddEntry:241 : Add entry (null) (nil) 2017-03-10 15:04:26.071+0000: 16378: debug : virConfAddEntry:241 : Add entry (null) (nil) 2017-03-10 15:04:26.071+0000: 16378: debug : virConfAddEntry:241 : Add entry (null) (nil) 2017-03-10 15:04:26.071+0000: 16378: debug : virConfAddEntry:241 : Add entry (null) (nil) 2017-03-10 15:04:26.071+0000: 16378: debug : virConfAddEntry:241 : Add entry (null) (nil) 2017-03-10 15:04:26.071+0000: 16378: debug : virConfGetValueStringList:981 : Get value string list (nil) 0 2017-03-10 15:04:26.071+0000: 16378: debug : virConnectOpenInternal:1033 : Split "qemu:///system" to URI components:
  scheme qemu
  server <null>
  user <null>
  port -1
  path /system
2017-03-10 15:04:26.071+0000: 16378: debug : virConnectOpenInternal:1083 : trying driver 0 (Test) ... 2017-03-10 15:04:26.071+0000: 16378: debug : virConnectOpenInternal:1098 : driver 0 Test returned DECLINED 2017-03-10 15:04:26.071+0000: 16378: debug : virConnectOpenInternal:1083 : trying driver 1 (VMWARE) ... 2017-03-10 15:04:26.071+0000: 16378: debug : virConnectOpenInternal:1098 : driver 1 VMWARE returned DECLINED 2017-03-10 15:04:26.071+0000: 16378: debug : virConnectOpenInternal:1083 : trying driver 2 (ESX) ... 2017-03-10 15:04:26.071+0000: 16378: debug : virConnectOpenInternal:1098 : driver 2 ESX returned DECLINED 2017-03-10 15:04:26.071+0000: 16378: debug : virConnectOpenInternal:1083 : trying driver 3 (remote) ... 2017-03-10 15:04:26.071+0000: 16378: debug : virConnectOpenInternal:1098 : driver 3 remote returned DECLINED 2017-03-10 15:04:26.071+0000: 16378: debug : virConnectOpenInternal:1083 : trying driver 4 (QEMU) ... 2017-03-10 15:04:26.071+0000: 16378: debug : virConnectOpenInternal:1098 : driver 4 QEMU returned SUCCESS 2017-03-10 15:04:26.071+0000: 16378: debug : virThreadJobClear:121 : Thread 16378 (virNetServerHandleJob) finished job remoteDispatchConnectOpen with ret=0 2017-03-10 15:04:26.072+0000: 16380: debug : virThreadJobSet:96 : Thread 16380 (virNetServerHandleJob) is now running job remoteDispatchConnectSupportsFeature 2017-03-10 15:04:26.072+0000: 16380: debug : virThreadJobClear:121 : Thread 16380 (virNetServerHandleJob) finished job remoteDispatchConnectSupportsFeature with ret=0 2017-03-10 15:04:26.072+0000: 16382: debug : virThreadJobSet:96 : Thread 16382 (virNetServerHandleJob) is now running job remoteDispatchConnectSupportsFeature 2017-03-10 15:04:26.072+0000: 16382: debug : virThreadJobClear:121 : Thread 16382 (virNetServerHandleJob) finished job remoteDispatchConnectSupportsFeature with ret=0 2017-03-10 15:04:26.072+0000: 16381: debug : virThreadJobSet:96 : Thread 16381 (virNetServerHandleJob) is now running job remoteDispatchConnectRegisterCloseCallback 2017-03-10 15:04:26.072+0000: 16381: debug : virConnectRegisterCloseCallback:1218 : conn=0x7f4e20002fe0 2017-03-10 15:04:26.072+0000: 16381: debug : virThreadJobClear:121 : Thread 16381 (virNetServerHandleJob) finished job remoteDispatchConnectRegisterCloseCallback with ret=0 2017-03-10 15:04:26.073+0000: 16379: debug : virThreadJobSet:96 : Thread 16379 (virNetServerHandleJob) is now running job remoteDispatchDomainLookupByName 2017-03-10 15:04:26.073+0000: 16379: debug : virDomainLookupByName:416 : conn=0x7f4e20002fe0, name=ESBEK-tor1 2017-03-10 15:04:26.073+0000: 16379: debug : virThreadJobClear:121 : Thread 16379 (virNetServerHandleJob) finished job remoteDispatchDomainLookupByName with ret=0 2017-03-10 15:04:26.074+0000: 16378: debug : virThreadJobSet:96 : Thread 16378 (virNetServerHandleJob) is now running job remoteDispatchConnectDomainEventCallbackRegisterAny 2017-03-10 15:04:26.074+0000: 16378: debug : virConnectDomainEventRegisterAny:9081 : dom=0x7f4e20002cd0, (VM: name=ESBEK-tor1, uuid=f40593c0-d196-bb4b-0886-f1b32f86c9a1), conn=0x7f4e20002fe0, eventID=8, cb=0x55ffc489d678, opaque=0x7f4e200035f0, freecb=0x55ffc489acf0 2017-03-10 15:04:26.074+0000: 16378: debug : virObjectEventCallbackListAddID:415 : conn=0x7f4e20002fe0 cblist=0x7f4dd81a1060 key=0x7f4e287cbb00 filter=(nil) filter_opaque=(nil) klass=0x7f4ddc012ce0 eventID=8 callback=0x55ffc489d678 opaque=0x7f4e200035f0 legacy=0 callbackID=0x7f4e287cbb94 serverFilter=0 2017-03-10 15:04:26.074+0000: 16378: debug : virThreadJobClear:121 : Thread 16378 (virNetServerHandleJob) finished job remoteDispatchConnectDomainEventCallbackRegisterAny with ret=0 2017-03-10 15:04:26.074+0000: 16380: debug : virThreadJobSet:96 : Thread 16380 (virNetServerHandleJob) is now running job remoteDispatchConnectDomainEventCallbackRegisterAny 2017-03-10 15:04:26.074+0000: 16380: debug : virConnectDomainEventRegisterAny:9081 : dom=0x7f4e10003210, (VM: name=ESBEK-tor1, uuid=f40593c0-d196-bb4b-0886-f1b32f86c9a1), conn=0x7f4e20002fe0, eventID=16, cb=0x55ffc489c8e0, opaque=0x7f4e10000cf0, freecb=0x55ffc489acf0 2017-03-10 15:04:26.074+0000: 16380: debug : virObjectEventCallbackListAddID:415 : conn=0x7f4e20002fe0 cblist=0x7f4dd81a1060 key=0x7f4e277c9b00 filter=(nil) filter_opaque=(nil) klass=0x7f4ddc012ce0 eventID=16 callback=0x55ffc489c8e0 opaque=0x7f4e10000cf0 legacy=0 callbackID=0x7f4e277c9b94 serverFilter=0 2017-03-10 15:04:26.075+0000: 16380: debug : virThreadJobClear:121 : Thread 16380 (virNetServerHandleJob) finished job remoteDispatchConnectDomainEventCallbackRegisterAny with ret=0 2017-03-10 15:04:26.075+0000: 16382: debug : virThreadJobSet:96 : Thread 16382 (virNetServerHandleJob) is now running job remoteDispatchDomainBlockCommit 2017-03-10 15:04:26.075+0000: 16382: debug : virDomainBlockCommit:10200 : dom=0x7f4e00003310, (VM: name=ESBEK-tor1, uuid=f40593c0-d196-bb4b-0886-f1b32f86c9a1), disk=vda, base=<null>, top=<null>, bandwidth=0, flags=4 2017-03-10 15:04:26.075+0000: 16382: debug : qemuDomainObjBeginJobInternal:3412 : Starting job: modify (vm=0x7f4dd81fd3c0 name=ESBEK-tor1, current job=none async=none) 2017-03-10 15:04:26.075+0000: 16382: debug : qemuDomainObjBeginJobInternal:3453 : Started job: modify (async=none vm=0x7f4dd81fd3c0 name=ESBEK-tor1) 2017-03-10 15:04:26.075+0000: 16382: debug : qemuSetupImagePathCgroup:72 : Allow path /data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img, perms: rw 2017-03-10 15:04:26.090+0000: 16382: debug : qemuDomainObjEnterMonitorInternal:3676 : Entering monitor (mon=0x7f4ddc000ec0 vm=0x7f4dd81fd3c0 name=ESBEK-tor1) 2017-03-10 15:04:26.090+0000: 16382: debug : qemuMonitorDiskNameLookup:3286 : mon:0x7f4ddc000ec0 vm:0x7f4dd81fd3c0 json:1 fd:20 2017-03-10 15:04:26.090+0000: 16382: debug : qemuMonitorJSONCommandWithFd:296 : Send command '{"execute":"query-block","id":"libvirt-27"}' for write with FD -1 2017-03-10 15:04:26.090+0000: 16382: info : qemuMonitorSend:1009 : QEMU_MONITOR_SEND_MSG: mon=0x7f4ddc000ec0 msg={"execute":"query-block","id":"libvirt-27"}
 fd=-1
2017-03-10 15:04:26.090+0000: 16377: info : qemuMonitorIOWrite:534 : QEMU_MONITOR_IO_WRITE: mon=0x7f4ddc000ec0 buf={"execute":"query-block","id":"libvirt-27"}
 len=45 ret=45 errno=0
2017-03-10 15:04:26.093+0000: 16377: info : qemuMonitorIOProcess:429 : QEMU_MONITOR_IO_PROCESS: mon=0x7f4ddc000ec0 buf={"return": [{"io-status": "ok", "device": "drive-ide0-1-0", "locked": false, "removable": true, "tray_open": false, "type": "unknown"}, {"io-status": "ok", "device": "drive-virtio-disk0", "locked": false, "removable": false, "inserted": {"iops_rd": 1000, "detect_zeroes": "off", "image": {"backing-image": {"virtual-size": 10737418240, "filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "format": "raw", "actual-size": 1400521216, "dirty-flag": false}, "backing-filename-format": "raw", "virtual-size": 10737418240, "filename": "/data/volumes/pool2/ESBEK/snap/ESBEK-tor1-sys.img.qcow2", "cluster-size": 65536, "format": "qcow2", "actual-size": 29184, "format-specific": {"type": "qcow2", "data": {"compat": "1.1", "lazy-refcounts": false, "refcount-bits": 16, "corrupt": false}}, "full-backing-filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "backing-filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "dirty-flag": false}, "iops_wr": 1000, "group": "drive-virtio-disk0", "ro": false, "node-name len=1023 2017-03-10 15:04:26.093+0000: 16377: debug : qemuMonitorJSONIOProcess:260 : Total used 0 bytes out of 1023 available in buffer 2017-03-10 15:04:26.093+0000: 16377: info : qemuMonitorIOProcess:429 : QEMU_MONITOR_IO_PROCESS: mon=0x7f4ddc000ec0 buf={"return": [{"io-status": "ok", "device": "drive-ide0-1-0", "locked": false, "removable": true, "tray_open": false, "type": "unknown"}, {"io-status": "ok", "device": "drive-virtio-disk0", "locked": false, "removable": false, "inserted": {"iops_rd": 1000, "detect_zeroes": "off", "image": {"backing-image": {"virtual-size": 10737418240, "filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "format": "raw", "actual-size": 1400521216, "dirty-flag": false}, "backing-filename-format": "raw", "virtual-size": 10737418240, "filename": "/data/volumes/pool2/ESBEK/snap/ESBEK-tor1-sys.img.qcow2", "cluster-size": 65536, "format": "qcow2", "actual-size": 29184, "format-specific": {"type": "qcow2", "data": {"compat": "1.1", "lazy-refcounts": false, "refcount-bits": 16, "corrupt": false}}, "full-backing-filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "backing-filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "dirty-flag": false}, "iops_wr": 1000, "group": "drive-virtio-disk0", "ro": false, "node-name": "#block382", "bps_wr_max_length": 1, "backing_file_depth": 1, "iops_rd_max_length": 1, "bps_wr_max": 10485760, "bps_rd_max_length": 1, "drv": "qcow2", "iops_rd_max": 100, "iops": 0, "bps_wr": 104857600, "bps_rd_max": 10485760, "write_threshold": 0, "backing_file": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "encrypted": false, "bps": 0, "bps_rd": 104857600, "cache": {"no-flush": false, "direct": false, "writeback": false}, "file": "/data/volumes/pool2/ESBEK/snap/ESBEK-tor1-sys.img.qcow2", "iops_wr_max_length": 1, "encryption_key_missing": false, "iops_wr_max": 100}, "type": "unknown"}], "id": "libvirt-27"}
 len=1645
2017-03-10 15:04:26.093+0000: 16377: debug : qemuMonitorJSONIOProcessLine:191 : Line [{"return": [{"io-status": "ok", "device": "drive-ide0-1-0", "locked": false, "removable": true, "tray_open": false, "type": "unknown"}, {"io-status": "ok", "device": "drive-virtio-disk0", "locked": false, "removable": false, "inserted": {"iops_rd": 1000, "detect_zeroes": "off", "image": {"backing-image": {"virtual-size": 10737418240, "filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "format": "raw", "actual-size": 1400521216, "dirty-flag": false}, "backing-filename-format": "raw", "virtual-size": 10737418240, "filename": "/data/volumes/pool2/ESBEK/snap/ESBEK-tor1-sys.img.qcow2", "cluster-size": 65536, "format": "qcow2", "actual-size": 29184, "format-specific": {"type": "qcow2", "data": {"compat": "1.1", "lazy-refcounts": false, "refcount-bits": 16, "corrupt": false}}, "full-backing-filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "backing-filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "dirty-flag": false}, "iops_wr": 1000, "group": "drive-virtio-disk0", "ro": false, "node-name": "#block382", "bps_wr_max_length": 1, "backing_file_depth": 1, "iops_rd_max_length": 1, "bps_wr_max": 10485760, "bps_rd_max_length": 1, "drv": "qcow2", "iops_rd_max": 100, "iops": 0, "bps_wr": 104857600, "bps_rd_max": 10485760, "write_threshold": 0, "backing_file": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "encrypted": false, "bps": 0, "bps_rd": 104857600, "cache": {"no-flush": false, "direct": false, "writeback": false}, "file": "/data/volumes/pool2/ESBEK/snap/ESBEK-tor1-sys.img.qcow2", "iops_wr_max_length": 1, "encryption_key_missing": false, "iops_wr_max": 100}, "type": "unknown"}], "id": "libvirt-27"}] 2017-03-10 15:04:26.094+0000: 16377: info : qemuMonitorJSONIOProcessLine:211 : QEMU_MONITOR_RECV_REPLY: mon=0x7f4ddc000ec0 reply={"return": [{"io-status": "ok", "device": "drive-ide0-1-0", "locked": false, "removable": true, "tray_open": false, "type": "unknown"}, {"io-status": "ok", "device": "drive-virtio-disk0", "locked": false, "removable": false, "inserted": {"iops_rd": 1000, "detect_zeroes": "off", "image": {"backing-image": {"virtual-size": 10737418240, "filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "format": "raw", "actual-size": 1400521216, "dirty-flag": false}, "backing-filename-format": "raw", "virtual-size": 10737418240, "filename": "/data/volumes/pool2/ESBEK/snap/ESBEK-tor1-sys.img.qcow2", "cluster-size": 65536, "format": "qcow2", "actual-size": 29184, "format-specific": {"type": "qcow2", "data": {"compat": "1.1", "lazy-refcounts": false, "refcount-bits": 16, "corrupt": false}}, "full-backing-filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "backing-filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "dirty-flag": false}, "iops_wr": 1000, "group": "drive-virtio-disk0", "ro": false, "node-name": "#block382", "bps_wr_max_length": 1, "backing_file_depth": 1, "iops_rd_max_length": 1, "bps_wr_max": 10485760, "bps_rd_max_length": 1, "drv": "qcow2", "iops_rd_max": 100, "iops": 0, "bps_wr": 104857600, "bps_rd_max": 10485760, "write_threshold": 0, "backing_file": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "encrypted": false, "bps": 0, "bps_rd": 104857600, "cache": {"no-flush": false, "direct": false, "writeback": false}, "file": "/data/volumes/pool2/ESBEK/snap/ESBEK-tor1-sys.img.qcow2", "iops_wr_max_length": 1, "encryption_key_missing": false, "iops_wr_max": 100}, "type": "unknown"}], "id": "libvirt-27"} 2017-03-10 15:04:26.094+0000: 16377: debug : qemuMonitorJSONIOProcess:260 : Total used 1645 bytes out of 1645 available in buffer 2017-03-10 15:04:26.094+0000: 16382: debug : qemuMonitorJSONCommandWithFd:301 : Receive command reply ret=0 rxObject=0x55ffc58d0930 2017-03-10 15:04:26.094+0000: 16382: debug : qemuMonitorDiskNameLookup:3286 : mon:0x7f4ddc000ec0 vm:0x7f4dd81fd3c0 json:1 fd:20 2017-03-10 15:04:26.094+0000: 16382: debug : qemuMonitorJSONCommandWithFd:296 : Send command '{"execute":"query-block","id":"libvirt-28"}' for write with FD -1 2017-03-10 15:04:26.094+0000: 16382: info : qemuMonitorSend:1009 : QEMU_MONITOR_SEND_MSG: mon=0x7f4ddc000ec0 msg={"execute":"query-block","id":"libvirt-28"}
 fd=-1
2017-03-10 15:04:26.094+0000: 16377: info : qemuMonitorIOWrite:534 : QEMU_MONITOR_IO_WRITE: mon=0x7f4ddc000ec0 buf={"execute":"query-block","id":"libvirt-28"}
 len=45 ret=45 errno=0
2017-03-10 15:04:26.096+0000: 16377: info : qemuMonitorIOProcess:429 : QEMU_MONITOR_IO_PROCESS: mon=0x7f4ddc000ec0 buf={"return": [{"io-status": "ok", "device": "drive-ide0-1-0", "locked": false, "removable": true, "tray_open": false, "type": "unknown"}, {"io-status": "ok", "device": "drive-virtio-disk0", "locked": false, "removable": false, "inserted": {"iops_rd": 1000, "detect_zeroes": "off", "image": {"backing-image": {"virtual-size": 10737418240, "filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "format": "raw", "actual-size": 1400521216, "dirty-flag": false}, "backing-filename-format": "raw", "virtual-size": 10737418240, "filename": "/data/volumes/pool2/ESBEK/snap/ESBEK-tor1-sys.img.qcow2", "cluster-size": 65536, "format": "qcow2", "actual-size": 29184, "format-specific": {"type": "qcow2", "data": {"compat": "1.1", "lazy-refcounts": false, "refcount-bits": 16, "corrupt": false}}, "full-backing-filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "backing-filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "dirty-flag": false}, "iops_wr": 1000, "group": "drive-virtio-disk0", "ro": false, "node-name len=1023 2017-03-10 15:04:26.096+0000: 16377: debug : qemuMonitorJSONIOProcess:260 : Total used 0 bytes out of 1023 available in buffer 2017-03-10 15:04:26.096+0000: 16377: info : qemuMonitorIOProcess:429 : QEMU_MONITOR_IO_PROCESS: mon=0x7f4ddc000ec0 buf={"return": [{"io-status": "ok", "device": "drive-ide0-1-0", "locked": false, "removable": true, "tray_open": false, "type": "unknown"}, {"io-status": "ok", "device": "drive-virtio-disk0", "locked": false, "removable": false, "inserted": {"iops_rd": 1000, "detect_zeroes": "off", "image": {"backing-image": {"virtual-size": 10737418240, "filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "format": "raw", "actual-size": 1400521216, "dirty-flag": false}, "backing-filename-format": "raw", "virtual-size": 10737418240, "filename": "/data/volumes/pool2/ESBEK/snap/ESBEK-tor1-sys.img.qcow2", "cluster-size": 65536, "format": "qcow2", "actual-size": 29184, "format-specific": {"type": "qcow2", "data": {"compat": "1.1", "lazy-refcounts": false, "refcount-bits": 16, "corrupt": false}}, "full-backing-filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "backing-filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "dirty-flag": false}, "iops_wr": 1000, "group": "drive-virtio-disk0", "ro": false, "node-name": "#block382", "bps_wr_max_length": 1, "backing_file_depth": 1, "iops_rd_max_length": 1, "bps_wr_max": 10485760, "bps_rd_max_length": 1, "drv": "qcow2", "iops_rd_max": 100, "iops": 0, "bps_wr": 104857600, "bps_rd_max": 10485760, "write_threshold": 0, "backing_file": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "encrypted": false, "bps": 0, "bps_rd": 104857600, "cache": {"no-flush": false, "direct": false, "writeback": false}, "file": "/data/volumes/pool2/ESBEK/snap/ESBEK-tor1-sys.img.qcow2", "iops_wr_max_length": 1, "encryption_key_missing": false, "iops_wr_max": 100}, "type": "unknown"}], "id": "libvirt-28"}
 len=1645
2017-03-10 15:04:26.096+0000: 16377: debug : qemuMonitorJSONIOProcessLine:191 : Line [{"return": [{"io-status": "ok", "device": "drive-ide0-1-0", "locked": false, "removable": true, "tray_open": false, "type": "unknown"}, {"io-status": "ok", "device": "drive-virtio-disk0", "locked": false, "removable": false, "inserted": {"iops_rd": 1000, "detect_zeroes": "off", "image": {"backing-image": {"virtual-size": 10737418240, "filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "format": "raw", "actual-size": 1400521216, "dirty-flag": false}, "backing-filename-format": "raw", "virtual-size": 10737418240, "filename": "/data/volumes/pool2/ESBEK/snap/ESBEK-tor1-sys.img.qcow2", "cluster-size": 65536, "format": "qcow2", "actual-size": 29184, "format-specific": {"type": "qcow2", "data": {"compat": "1.1", "lazy-refcounts": false, "refcount-bits": 16, "corrupt": false}}, "full-backing-filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "backing-filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "dirty-flag": false}, "iops_wr": 1000, "group": "drive-virtio-disk0", "ro": false, "node-name": "#block382", "bps_wr_max_length": 1, "backing_file_depth": 1, "iops_rd_max_length": 1, "bps_wr_max": 10485760, "bps_rd_max_length": 1, "drv": "qcow2", "iops_rd_max": 100, "iops": 0, "bps_wr": 104857600, "bps_rd_max": 10485760, "write_threshold": 0, "backing_file": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "encrypted": false, "bps": 0, "bps_rd": 104857600, "cache": {"no-flush": false, "direct": false, "writeback": false}, "file": "/data/volumes/pool2/ESBEK/snap/ESBEK-tor1-sys.img.qcow2", "iops_wr_max_length": 1, "encryption_key_missing": false, "iops_wr_max": 100}, "type": "unknown"}], "id": "libvirt-28"}] 2017-03-10 15:04:26.096+0000: 16377: info : qemuMonitorJSONIOProcessLine:211 : QEMU_MONITOR_RECV_REPLY: mon=0x7f4ddc000ec0 reply={"return": [{"io-status": "ok", "device": "drive-ide0-1-0", "locked": false, "removable": true, "tray_open": false, "type": "unknown"}, {"io-status": "ok", "device": "drive-virtio-disk0", "locked": false, "removable": false, "inserted": {"iops_rd": 1000, "detect_zeroes": "off", "image": {"backing-image": {"virtual-size": 10737418240, "filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "format": "raw", "actual-size": 1400521216, "dirty-flag": false}, "backing-filename-format": "raw", "virtual-size": 10737418240, "filename": "/data/volumes/pool2/ESBEK/snap/ESBEK-tor1-sys.img.qcow2", "cluster-size": 65536, "format": "qcow2", "actual-size": 29184, "format-specific": {"type": "qcow2", "data": {"compat": "1.1", "lazy-refcounts": false, "refcount-bits": 16, "corrupt": false}}, "full-backing-filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "backing-filename": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "dirty-flag": false}, "iops_wr": 1000, "group": "drive-virtio-disk0", "ro": false, "node-name": "#block382", "bps_wr_max_length": 1, "backing_file_depth": 1, "iops_rd_max_length": 1, "bps_wr_max": 10485760, "bps_rd_max_length": 1, "drv": "qcow2", "iops_rd_max": 100, "iops": 0, "bps_wr": 104857600, "bps_rd_max": 10485760, "write_threshold": 0, "backing_file": "/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img", "encrypted": false, "bps": 0, "bps_rd": 104857600, "cache": {"no-flush": false, "direct": false, "writeback": false}, "file": "/data/volumes/pool2/ESBEK/snap/ESBEK-tor1-sys.img.qcow2", "iops_wr_max_length": 1, "encryption_key_missing": false, "iops_wr_max": 100}, "type": "unknown"}], "id": "libvirt-28"} 2017-03-10 15:04:26.096+0000: 16377: debug : qemuMonitorJSONIOProcess:260 : Total used 1645 bytes out of 1645 available in buffer 2017-03-10 15:04:26.096+0000: 16382: debug : qemuMonitorJSONCommandWithFd:301 : Receive command reply ret=0 rxObject=0x55ffc58d0930 2017-03-10 15:04:26.097+0000: 16382: debug : qemuMonitorBlockCommit:3258 : device=drive-virtio-disk0, top=/data/volumes/pool2/ESBEK/snap/ESBEK-tor1-sys.img.qcow2, base=/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img, backingName=<null>, bandwidth=0 2017-03-10 15:04:26.097+0000: 16382: debug : qemuMonitorBlockCommit:3260 : mon:0x7f4ddc000ec0 vm:0x7f4dd81fd3c0 json:1 fd:20 2017-03-10 15:04:26.097+0000: 16382: debug : qemuMonitorJSONCommandWithFd:296 : Send command '{"execute":"block-commit","arguments":{"device":"drive-virtio-disk0","top":"/data/volumes/pool2/ESBEK/snap/ESBEK-tor1-sys.img.qcow2","base":"/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img"},"id":"libvirt-29"}' for write with FD -1 2017-03-10 15:04:26.097+0000: 16382: info : qemuMonitorSend:1009 : QEMU_MONITOR_SEND_MSG: mon=0x7f4ddc000ec0 msg={"execute":"block-commit","arguments":{"device":"drive-virtio-disk0","top":"/data/volumes/pool2/ESBEK/snap/ESBEK-tor1-sys.img.qcow2","base":"/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img"},"id":"libvirt-29"}
 fd=-1
2017-03-10 15:04:26.097+0000: 16377: info : qemuMonitorIOWrite:534 : QEMU_MONITOR_IO_WRITE: mon=0x7f4ddc000ec0 buf={"execute":"block-commit","arguments":{"device":"drive-virtio-disk0","top":"/data/volumes/pool2/ESBEK/snap/ESBEK-tor1-sys.img.qcow2","base":"/data/volumes/pool2/ESBEK/ESBEK-tor1-sys.img"},"id":"libvirt-29"}
 len=208 ret=208 errno=0
2017-03-10 15:04:26.110+0000: 16377: info : qemuMonitorIOProcess:429 : QEMU_MONITOR_IO_PROCESS: mon=0x7f4ddc000ec0 buf={"return": {}, "id": "libvirt-29"}
 len=36
2017-03-10 15:04:26.110+0000: 16377: debug : qemuMonitorJSONIOProcessLine:191 : Line [{"return": {}, "id": "libvirt-29"}] 2017-03-10 15:04:26.110+0000: 16377: info : qemuMonitorJSONIOProcessLine:211 : QEMU_MONITOR_RECV_REPLY: mon=0x7f4ddc000ec0 reply={"return": {}, "id": "libvirt-29"} 2017-03-10 15:04:26.110+0000: 16377: debug : qemuMonitorJSONIOProcess:260 : Total used 36 bytes out of 36 available in buffer 2017-03-10 15:04:26.110+0000: 16382: debug : qemuMonitorJSONCommandWithFd:301 : Receive command reply ret=0 rxObject=0x55ffc58d0930 2017-03-10 15:04:26.110+0000: 16382: debug : qemuDomainObjExitMonitorInternal:3699 : Exited monitor (mon=0x7f4ddc000ec0 vm=0x7f4dd81fd3c0 name=ESBEK-tor1) 2017-03-10 15:04:26.111+0000: 16382: debug : qemuDomainObjEndJob:3607 : Stopping job: modify (async=none vm=0x7f4dd81fd3c0 name=ESBEK-tor1) 2017-03-10 15:04:26.111+0000: 16382: debug : virThreadJobClear:121 : Thread 16382 (virNetServerHandleJob) finished job remoteDispatchDomainBlockCommit with ret=0 2017-03-10 15:04:26.111+0000: 16381: debug : virThreadJobSet:96 : Thread 16381 (virNetServerHandleJob) is now running job remoteDispatchDomainGetBlockJobInfo 2017-03-10 15:04:26.111+0000: 16381: debug : virDomainGetBlockJobInfo:9654 : dom=0x7f4e08000e70, (VM: name=ESBEK-tor1, uuid=f40593c0-d196-bb4b-0886-f1b32f86c9a1), disk=vda, info=0x7f4e26fc8c70, flags=0 2017-03-10 15:04:26.111+0000: 16381: debug : qemuDomainObjBeginJobInternal:3412 : Starting job: query (vm=0x7f4dd81fd3c0 name=ESBEK-tor1, current job=none async=none) 2017-03-10 15:04:26.111+0000: 16381: debug : qemuDomainObjBeginJobInternal:3453 : Started job: query (async=none vm=0x7f4dd81fd3c0 name=ESBEK-tor1) 2017-03-10 15:04:26.111+0000: 16381: debug : qemuDomainObjEnterMonitorInternal:3676 : Entering monitor (mon=0x7f4ddc000ec0 vm=0x7f4dd81fd3c0 name=ESBEK-tor1) 2017-03-10 15:04:26.111+0000: 16381: debug : qemuMonitorGetBlockJobInfo:3434 : alias=virtio-disk0, info=0x7f4e26fc8b90 2017-03-10 15:04:26.111+0000: 16381: debug : qemuMonitorGetAllBlockJobInfo:3415 : mon:0x7f4ddc000ec0 vm:0x7f4dd81fd3c0 json:1 fd:20 2017-03-10 15:04:26.111+0000: 16381: debug : qemuMonitorJSONCommandWithFd:296 : Send command '{"execute":"query-block-jobs","id":"libvirt-30"}' for write with FD -1 2017-03-10 15:04:26.111+0000: 16381: info : qemuMonitorSend:1009 : QEMU_MONITOR_SEND_MSG: mon=0x7f4ddc000ec0 msg={"execute":"query-block-jobs","id":"libvirt-30"}
 fd=-1
2017-03-10 15:04:26.111+0000: 16377: info : qemuMonitorIOWrite:534 : QEMU_MONITOR_IO_WRITE: mon=0x7f4ddc000ec0 buf={"execute":"query-block-jobs","id":"libvirt-30"}
 len=50 ret=50 errno=0
2017-03-10 15:04:26.115+0000: 16377: info : qemuMonitorIOProcess:429 : QEMU_MONITOR_IO_PROCESS: mon=0x7f4ddc000ec0 buf={"timestamp": {"seconds": 1489158266, "microseconds": 115061}, "event": "BLOCK_JOB_READY", "data": {"device": "drive-virtio-disk0", "len": 65536, "offset": 65536, "speed": 0, "type": "commit"}}
 len=195
2017-03-10 15:04:26.115+0000: 16377: debug : qemuMonitorJSONIOProcessLine:191 : Line [{"timestamp": {"seconds": 1489158266, "microseconds": 115061}, "event": "BLOCK_JOB_READY", "data": {"device": "drive-virtio-disk0", "len": 65536, "offset": 65536, "speed": 0, "type": "commit"}}] 2017-03-10 15:04:26.115+0000: 16377: info : qemuMonitorJSONIOProcessLine:206 : QEMU_MONITOR_RECV_EVENT: mon=0x7f4ddc000ec0 event={"timestamp": {"seconds": 1489158266, "microseconds": 115061}, "event": "BLOCK_JOB_READY", "data": {"device": "drive-virtio-disk0", "len": 65536, "offset": 65536, "speed": 0, "type": "commit"}} 2017-03-10 15:04:26.115+0000: 16377: debug : qemuMonitorJSONIOProcessEvent:152 : mon=0x7f4ddc000ec0 obj=0x55ffc58d7e20 2017-03-10 15:04:26.115+0000: 16377: debug : qemuMonitorEmitEvent:1272 : mon=0x7f4ddc000ec0 event=BLOCK_JOB_READY 2017-03-10 15:04:26.115+0000: 16377: debug : qemuProcessHandleEvent:617 : vm=0x7f4dd81fd3c0 2017-03-10 15:04:26.115+0000: 16377: debug : virObjectEventNew:640 : obj=0x55ffc58d0760 2017-03-10 15:04:26.115+0000: 16377: debug : qemuMonitorJSONIOProcessEvent:177 : handle BLOCK_JOB_READY handler=0x7f4e1cd3aed0 data=0x55ffc58d8d50 2017-03-10 15:04:26.115+0000: 16377: debug : qemuMonitorEmitBlockJob:1464 : mon=0x7f4ddc000ec0 2017-03-10 15:04:26.115+0000: 16377: debug : qemuProcessHandleBlockJob:976 : Block job for device drive-virtio-disk0 (domain: 0x7f4dd81fd3c0,ESBEK-tor1) type 3 status 3 2017-03-10 15:04:26.115+0000: 16377: debug : qemuMonitorJSONIOProcess:260 : Total used 195 bytes out of 195 available in buffer 2017-03-10 15:04:26.115+0000: 16377: debug : virObjectEventDispose:134 : obj=0x55ffc58d0760 2017-03-10 15:04:26.115+0000: 16377: info : qemuMonitorIOProcess:429 : QEMU_MONITOR_IO_PROCESS: mon=0x7f4ddc000ec0 buf={"return": [{"io-status": "ok", "device": "drive-virtio-disk0", "busy": false, "len": 65536, "offset": 65536, "paused": false, "speed": 0, "ready": true, "type": "commit"}], "id": "libvirt-30"}
 len=195
2017-03-10 15:04:26.115+0000: 16377: debug : qemuMonitorJSONIOProcessLine:191 : Line [{"return": [{"io-status": "ok", "device": "drive-virtio-disk0", "busy": false, "len": 65536, "offset": 65536, "paused": false, "speed": 0, "ready": true, "type": "commit"}], "id": "libvirt-30"}] 2017-03-10 15:04:26.115+0000: 16377: info : qemuMonitorJSONIOProcessLine:211 : QEMU_MONITOR_RECV_REPLY: mon=0x7f4ddc000ec0 reply={"return": [{"io-status": "ok", "device": "drive-virtio-disk0", "busy": false, "len": 65536, "offset": 65536, "paused": false, "speed": 0, "ready": true, "type": "commit"}], "id": "libvirt-30"} 2017-03-10 15:04:26.115+0000: 16377: debug : qemuMonitorJSONIOProcess:260 : Total used 195 bytes out of 195 available in buffer 2017-03-10 15:04:26.115+0000: 19721: debug : virThreadJobSetWorker:77 : Thread 19721 is running worker qemuProcessEventHandler 2017-03-10 15:04:26.116+0000: 16381: debug : qemuMonitorJSONCommandWithFd:301 : Receive command reply ret=0 rxObject=0x55ffc58d7e20 2017-03-10 15:04:26.116+0000: 19721: debug : qemuProcessEventHandler:4579 : vm=0x7f4dd81fd3c0, event=5 2017-03-10 15:04:26.116+0000: 19721: debug : qemuDomainObjBeginJobInternal:3412 : Starting job: modify (vm=0x7f4dd81fd3c0 name=ESBEK-tor1, current job=query async=none) 2017-03-10 15:04:26.116+0000: 19721: debug : qemuDomainObjBeginJobInternal:3435 : Waiting for job (vm=0x7f4dd81fd3c0 name=ESBEK-tor1) 2017-03-10 15:04:26.116+0000: 16381: debug : qemuDomainObjExitMonitorInternal:3699 : Exited monitor (mon=0x7f4ddc000ec0 vm=0x7f4dd81fd3c0 name=ESBEK-tor1) 2017-03-10 15:04:26.116+0000: 16381: debug : qemuDomainObjEndJob:3607 : Stopping job: query (async=none vm=0x7f4dd81fd3c0 name=ESBEK-tor1) 2017-03-10 15:04:26.116+0000: 19721: debug : qemuDomainObjBeginJobInternal:3453 : Started job: modify (async=none vm=0x7f4dd81fd3c0 name=ESBEK-tor1) 2017-03-10 15:04:26.116+0000: 16381: debug : virThreadJobClear:121 : Thread 16381 (virNetServerHandleJob) finished job remoteDispatchDomainGetBlockJobInfo with ret=0 2017-03-10 15:04:26.117+0000: 19721: debug : qemuBlockJobEventProcess:104 : disk=vda, mirrorState=yes, type=3, status=3 2017-03-10 15:04:26.117+0000: 19721: debug : virObjectEventNew:640 : obj=0x7f4ddc013480 2017-03-10 15:04:26.117+0000: 19721: debug : virObjectEventNew:640 : obj=0x7f4ddc012970 2017-03-10 15:04:26.117+0000: 19721: debug : qemuDomainObjEndJob:3607 : Stopping job: modify (async=none vm=0x7f4dd81fd3c0 name=ESBEK-tor1) 2017-03-10 15:04:26.117+0000: 16377: debug : virObjectEventDispose:134 : obj=0x7f4ddc013480 2017-03-10 15:04:26.117+0000: 16377: debug : virObjectEventDispose:134 : obj=0x7f4ddc012970 2017-03-10 15:04:26.617+0000: 16379: debug : virThreadJobSet:96 : Thread 16379 (virNetServerHandleJob) is now running job remoteDispatchDomainGetBlockJobInfo 2017-03-10 15:04:26.617+0000: 16379: debug : virDomainGetBlockJobInfo:9654 : dom=0x7f4e18000b60, (VM: name=ESBEK-tor1, uuid=f40593c0-d196-bb4b-0886-f1b32f86c9a1), disk=vda, info=0x7f4e27fcac70, flags=0 2017-03-10 15:04:26.617+0000: 16379: debug : qemuDomainObjBeginJobInternal:3412 : Starting job: query (vm=0x7f4dd81fd3c0 name=ESBEK-tor1, current job=none async=none) 2017-03-10 15:04:26.617+0000: 16379: debug : qemuDomainObjBeginJobInternal:3453 : Started job: query (async=none vm=0x7f4dd81fd3c0 name=ESBEK-tor1) 2017-03-10 15:04:26.617+0000: 16379: debug : qemuDomainObjEnterMonitorInternal:3676 : Entering monitor (mon=0x7f4ddc000ec0 vm=0x7f4dd81fd3c0 name=ESBEK-tor1) 2017-03-10 15:04:26.617+0000: 16379: debug : qemuMonitorGetBlockJobInfo:3434 : alias=virtio-disk0, info=0x7f4e27fcab90 2017-03-10 15:04:26.617+0000: 16379: debug : qemuMonitorGetAllBlockJobInfo:3415 : mon:0x7f4ddc000ec0 vm:0x7f4dd81fd3c0 json:1 fd:20 2017-03-10 15:04:26.617+0000: 16379: debug : qemuMonitorJSONCommandWithFd:296 : Send command '{"execute":"query-block-jobs","id":"libvirt-31"}' for write with FD -1 2017-03-10 15:04:26.617+0000: 16379: info : qemuMonitorSend:1009 : QEMU_MONITOR_SEND_MSG: mon=0x7f4ddc000ec0 msg={"execute":"query-block-jobs","id":"libvirt-31"}
 fd=-1
2017-03-10 15:04:26.618+0000: 16377: info : qemuMonitorIOWrite:534 : QEMU_MONITOR_IO_WRITE: mon=0x7f4ddc000ec0 buf={"execute":"query-block-jobs","id":"libvirt-31"}
 len=50 ret=50 errno=0
2017-03-10 15:04:26.619+0000: 16377: info : qemuMonitorIOProcess:429 : QEMU_MONITOR_IO_PROCESS: mon=0x7f4ddc000ec0 buf={"return": [{"io-status": "ok", "device": "drive-virtio-disk0", "busy": false, "len": 65536, "offset": 65536, "paused": false, "speed": 0, "ready": true, "type": "commit"}], "id": "libvirt-31"}
 len=195
2017-03-10 15:04:26.619+0000: 16377: debug : qemuMonitorJSONIOProcessLine:191 : Line [{"return": [{"io-status": "ok", "device": "drive-virtio-disk0", "busy": false, "len": 65536, "offset": 65536, "paused": false, "speed": 0, "ready": true, "type": "commit"}], "id": "libvirt-31"}] 2017-03-10 15:04:26.619+0000: 16377: info : qemuMonitorJSONIOProcessLine:211 : QEMU_MONITOR_RECV_REPLY: mon=0x7f4ddc000ec0 reply={"return": [{"io-status": "ok", "device": "drive-virtio-disk0", "busy": false, "len": 65536, "offset": 65536, "paused": false, "speed": 0, "ready": true, "type": "commit"}], "id": "libvirt-31"} 2017-03-10 15:04:26.619+0000: 16377: debug : qemuMonitorJSONIOProcess:260 : Total used 195 bytes out of 195 available in buffer 2017-03-10 15:04:26.620+0000: 16379: debug : qemuMonitorJSONCommandWithFd:301 : Receive command reply ret=0 rxObject=0x55ffc58d8e00 2017-03-10 15:04:26.620+0000: 16379: debug : qemuDomainObjExitMonitorInternal:3699 : Exited monitor (mon=0x7f4ddc000ec0 vm=0x7f4dd81fd3c0 name=ESBEK-tor1) 2017-03-10 15:04:26.620+0000: 16379: debug : qemuDomainObjEndJob:3607 : Stopping job: query (async=none vm=0x7f4dd81fd3c0 name=ESBEK-tor1) 2017-03-10 15:04:26.620+0000: 16379: debug : virThreadJobClear:121 : Thread 16379 (virNetServerHandleJob) finished job remoteDispatchDomainGetBlockJobInfo with ret=0 2017-03-10 15:04:26.620+0000: 16378: debug : virThreadJobSet:96 : Thread 16378 (virNetServerHandleJob) is now running job remoteDispatchDomainBlockJobAbort 2017-03-10 15:04:26.620+0000: 16378: debug : virDomainBlockJobAbort:9592 : dom=0x7f4e20001040, (VM: name=ESBEK-tor1, uuid=f40593c0-d196-bb4b-0886-f1b32f86c9a1), disk=vda, flags=2 2017-03-10 15:04:26.620+0000: 16378: debug : qemuDomainObjBeginJobInternal:3412 : Starting job: modify (vm=0x7f4dd81fd3c0 name=ESBEK-tor1, current job=none async=none) 2017-03-10 15:04:26.620+0000: 16378: debug : qemuDomainObjBeginJobInternal:3453 : Started job: modify (async=none vm=0x7f4dd81fd3c0 name=ESBEK-tor1) 2017-03-10 15:04:26.620+0000: 16378: debug : qemuBlockJobSyncBegin:230 : disk=vda 2017-03-10 15:04:26.620+0000: 16378: debug : qemuDomainObjEnterMonitorInternal:3676 : Entering monitor (mon=0x7f4ddc000ec0 vm=0x7f4dd81fd3c0 name=ESBEK-tor1) 2017-03-10 15:04:26.620+0000: 16378: debug : qemuMonitorDrivePivot:3297 : device=drive-virtio-disk0 2017-03-10 15:04:26.620+0000: 16378: debug : qemuMonitorDrivePivot:3299 : mon:0x7f4ddc000ec0 vm:0x7f4dd81fd3c0 json:1 fd:20 2017-03-10 15:04:26.620+0000: 16378: debug : qemuMonitorJSONCommandWithFd:296 : Send command '{"execute":"block-job-complete","arguments":{"device":"drive-virtio-disk0"},"id":"libvirt-32"}' for write with FD -1 2017-03-10 15:04:26.620+0000: 16378: info : qemuMonitorSend:1009 : QEMU_MONITOR_SEND_MSG: mon=0x7f4ddc000ec0 msg={"execute":"block-job-complete","arguments":{"device":"drive-virtio-disk0"},"id":"libvirt-32"}
 fd=-1
2017-03-10 15:04:26.621+0000: 16377: info : qemuMonitorIOWrite:534 : QEMU_MONITOR_IO_WRITE: mon=0x7f4ddc000ec0 buf={"execute":"block-job-complete","arguments":{"device":"drive-virtio-disk0"},"id":"libvirt-32"}
 len=96 ret=96 errno=0
2017-03-10 15:04:26.624+0000: 16377: info : qemuMonitorIOProcess:429 : QEMU_MONITOR_IO_PROCESS: mon=0x7f4ddc000ec0 buf={"return": {}, "id": "libvirt-32"}
 len=36
2017-03-10 15:04:26.624+0000: 16377: debug : qemuMonitorJSONIOProcessLine:191 : Line [{"return": {}, "id": "libvirt-32"}] 2017-03-10 15:04:26.624+0000: 16377: info : qemuMonitorJSONIOProcessLine:211 : QEMU_MONITOR_RECV_REPLY: mon=0x7f4ddc000ec0 reply={"return": {}, "id": "libvirt-32"} 2017-03-10 15:04:26.624+0000: 16377: debug : qemuMonitorJSONIOProcess:260 : Total used 36 bytes out of 36 available in buffer 2017-03-10 15:04:26.624+0000: 16378: debug : qemuMonitorJSONCommandWithFd:301 : Receive command reply ret=0 rxObject=0x55ffc58d7e20 2017-03-10 15:04:26.624+0000: 16378: debug : qemuDomainObjExitMonitorInternal:3699 : Exited monitor (mon=0x7f4ddc000ec0 vm=0x7f4dd81fd3c0 name=ESBEK-tor1) 2017-03-10 15:04:26.624+0000: 16377: info : qemuMonitorIOProcess:429 : QEMU_MONITOR_IO_PROCESS: mon=0x7f4ddc000ec0 buf={"timestamp": {"seconds": 1489158266, "microseconds": 624625}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "drive-virtio-disk0", "len": 65536, "offset": 65536, "speed": 0, "type": "commit"}}
 len=199
2017-03-10 15:04:26.624+0000: 16377: debug : qemuMonitorJSONIOProcessLine:191 : Line [{"timestamp": {"seconds": 1489158266, "microseconds": 624625}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "drive-virtio-disk0", "len": 65536, "offset": 65536, "speed": 0, "type": "commit"}}] 2017-03-10 15:04:26.624+0000: 16377: info : qemuMonitorJSONIOProcessLine:206 : QEMU_MONITOR_RECV_EVENT: mon=0x7f4ddc000ec0 event={"timestamp": {"seconds": 1489158266, "microseconds": 624625}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "drive-virtio-disk0", "len": 65536, "offset": 65536, "speed": 0, "type": "commit"}} 2017-03-10 15:04:26.624+0000: 16377: debug : qemuMonitorJSONIOProcessEvent:152 : mon=0x7f4ddc000ec0 obj=0x55ffc58d7e20 2017-03-10 15:04:26.624+0000: 16377: debug : qemuMonitorEmitEvent:1272 : mon=0x7f4ddc000ec0 event=BLOCK_JOB_COMPLETED 2017-03-10 15:04:26.624+0000: 16377: debug : qemuProcessHandleEvent:617 : vm=0x7f4dd81fd3c0 2017-03-10 15:04:26.624+0000: 16377: debug : virObjectEventNew:640 : obj=0x55ffc58d0760 2017-03-10 15:04:26.624+0000: 16377: debug : qemuMonitorJSONIOProcessEvent:177 : handle BLOCK_JOB_COMPLETED handler=0x7f4e1cd3aee0 data=0x55ffc58d8d50 2017-03-10 15:04:26.624+0000: 16377: debug : qemuMonitorEmitBlockJob:1464 : mon=0x7f4ddc000ec0 2017-03-10 15:04:26.624+0000: 16377: debug : qemuProcessHandleBlockJob:976 : Block job for device drive-virtio-disk0 (domain: 0x7f4dd81fd3c0,ESBEK-tor1) type 3 status 0 2017-03-10 15:04:26.624+0000: 16377: debug : qemuMonitorJSONIOProcess:260 : Total used 199 bytes out of 199 available in buffer 2017-03-10 15:04:26.624+0000: 16378: debug : qemuBlockJobEventProcess:104 : disk=vda, mirrorState=pivot, type=3, status=0 2017-03-10 15:04:26.624+0000: 16377: debug : virObjectEventDispose:134 : obj=0x55ffc58d0760 2017-03-10 15:04:26.625+0000: 16378: debug : virObjectEventNew:640 : obj=0x7f4e200008e0 2017-03-10 15:04:26.625+0000: 16378: debug : virObjectEventNew:640 : obj=0x7f4e200032d0 2017-03-10 15:04:26.653+0000: 16378: debug : qemuBlockJobSyncEnd:250 : disk=vda 2017-03-10 15:04:26.653+0000: 16378: debug : qemuDomainObjEndJob:3607 : Stopping job: modify (async=none vm=0x7f4dd81fd3c0 name=ESBEK-tor1) 2017-03-10 15:04:26.653+0000: 16378: debug : virThreadJobClear:121 : Thread 16378 (virNetServerHandleJob) finished job remoteDispatchDomainBlockJobAbort with ret=0 2017-03-10 15:04:26.653+0000: 16377: debug : virObjectEventDispose:134 : obj=0x7f4e200008e0 2017-03-10 15:04:26.653+0000: 16377: debug : virObjectEventDispose:134 : obj=0x7f4e200032d0 2017-03-10 15:04:26.654+0000: 16380: debug : virThreadJobSet:96 : Thread 16380 (virNetServerHandleJob) is now running job remoteDispatchConnectDomainEventCallbackDeregisterAny 2017-03-10 15:04:26.654+0000: 16380: debug : virConnectDomainEventDeregisterAny:9134 : conn=0x7f4e20002fe0, callbackID=0 2017-03-10 15:04:26.654+0000: 16380: debug : virThreadJobClear:121 : Thread 16380 (virNetServerHandleJob) finished job remoteDispatchConnectDomainEventCallbackDeregisterAny with ret=0 2017-03-10 15:04:26.655+0000: 16382: debug : virThreadJobSet:96 : Thread 16382 (virNetServerHandleJob) is now running job remoteDispatchConnectDomainEventCallbackDeregisterAny 2017-03-10 15:04:26.655+0000: 16382: debug : virConnectDomainEventDeregisterAny:9134 : conn=0x7f4e20002fe0, callbackID=1 2017-03-10 15:04:26.655+0000: 16382: debug : virThreadJobClear:121 : Thread 16382 (virNetServerHandleJob) finished job remoteDispatchConnectDomainEventCallbackDeregisterAny with ret=0 2017-03-10 15:04:26.655+0000: 16381: debug : virThreadJobSet:96 : Thread 16381 (virNetServerHandleJob) is now running job remoteDispatchConnectUnregisterCloseCallback 2017-03-10 15:04:26.655+0000: 16381: debug : virConnectUnregisterCloseCallback:1253 : conn=0x7f4e20002fe0 2017-03-10 15:04:26.655+0000: 16381: debug : virThreadJobClear:121 : Thread 16381 (virNetServerHandleJob) finished job remoteDispatchConnectUnregisterCloseCallback with ret=0 2017-03-10 15:04:26.656+0000: 16379: debug : virThreadJobSet:96 : Thread 16379 (virNetServerHandleJob) is now running job remoteDispatchConnectClose 2017-03-10 15:04:26.656+0000: 16379: debug : virThreadJobClear:121 : Thread 16379 (virNetServerHandleJob) finished job remoteDispatchConnectClose with ret=0 2017-03-10 15:04:26.656+0000: 16377: debug : virIdentitySetAttr:248 : ident=0x55ffc58d17e0 attribute=4 value=16377 2017-03-10 15:04:26.656+0000: 16377: debug : virIdentitySetAttr:248 : ident=0x55ffc58d17e0 attribute=5 value=759159 2017-03-10 15:04:26.656+0000: 16377: debug : virIdentitySetAttr:248 : ident=0x55ffc58d17e0 attribute=0 value=root 2017-03-10 15:04:26.656+0000: 16377: debug : virIdentitySetAttr:248 : ident=0x55ffc58d17e0 attribute=1 value=0 2017-03-10 15:04:26.656+0000: 16377: debug : virIdentitySetAttr:248 : ident=0x55ffc58d17e0 attribute=2 value=root 2017-03-10 15:04:26.656+0000: 16377: debug : virIdentitySetAttr:248 : ident=0x55ffc58d17e0 attribute=3 value=0 2017-03-10 15:04:26.656+0000: 16377: debug : virConnectClose:1290 : conn=0x7f4e20002fe0 2017-03-10 15:04:26.656+0000: 16377: debug : virCloseCallbacksRun:325 : conn=0x7f4e20002fe0


Best regards
Piotr Rybicki




reply via email to

[Prev in Thread] Current Thread [Next in Thread]