2023-08-01 08:11:30.757 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG Starting new HTTP connection (1): consul:8500
2023-08-01 08:11:30.758 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG http://consul:8500 "PUT /v1/session/create HTTP/1.1" 200 77
2023-08-01 08:11:30.759 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG [ConsulSession#62cdbd81-1d49-6dd8-8494-5ff094bc4ba4]: session is created
2023-08-01 08:11:30.759 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG Check task abort job
2023-08-01 08:11:30.760 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG http://consul:8500 "PUT /v1/session/renew/62cdbd81-1d49-6dd8-8494-5ff094bc4ba4 HTTP/1.1" 200 213
2023-08-01 08:11:30.960 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG Starting new HTTP connection (1): input:1500
2023-08-01 08:11:30.962 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG http://input:1500 "GET /vm/v3/ssh_address?id_type=node&ip=172.31.36.47 HTTP/1.1" 200 1946
2023-08-01 08:11:30.962 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG ssh params: {'last_notify': 313871, 'ssh_address': '172.31.36.47', 'ssh_port': 22, 'ssh_user': 'root'}
2023-08-01 08:11:31.000 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG Connecting to root@172.31.36.47:22
2023-08-01 08:11:31.657 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG Starting new HTTP connection (1): consul:8500
2023-08-01 08:11:31.658 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG http://consul:8500 "PUT /v1/session/create HTTP/1.1" 200 77
2023-08-01 08:11:31.659 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG [ConsulSession#23218726-b284-3c53-477e-c19f87399d6f]: session is created
2023-08-01 08:11:31.660 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG Starting new HTTP connection (1): consul:8500
2023-08-01 08:11:31.660 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG http://consul:8500 "PUT /v1/session/renew/23218726-b284-3c53-477e-c19f87399d6f HTTP/1.1" 200 234
2023-08-01 08:11:31.661 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG http://consul:8500 "PUT /v1/kv/storage/6/lock?acquire=23218726-b284-3c53-477e-c19f87399d6f HTTP/1.1" 200 29
2023-08-01 08:11:31.661 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG [ConsulLock#storage/6/lock#23218726-b284-3c53-477e-c19f87399d6f]: lock is created
2023-08-01 08:11:31.661 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG run vgscan --cache && lvscan && virsh pool-refresh Network_lvm_dev_sda
2023-08-01 08:11:31.920 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG run lvcreate --size 10240 --snapshot --name '11_san_snapshot' '/dev/Network_lvm_dev_sda/11_san'
2023-08-01 08:11:32.316 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG http://consul:8500 "PUT /v1/kv/storage/6/lock?release=23218726-b284-3c53-477e-c19f87399d6f HTTP/1.1" 200 29
2023-08-01 08:11:32.317 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG [ConsulLock#storage/6/lock#23218726-b284-3c53-477e-c19f87399d6f]: lock is released
2023-08-01 08:11:32.318 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG http://consul:8500 "PUT /v1/session/destroy/23218726-b284-3c53-477e-c19f87399d6f HTTP/1.1" 200 29
2023-08-01 08:11:32.318 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG [ConsulSession#23218726-b284-3c53-477e-c19f87399d6f]: session is destroyed
2023-08-01 08:11:32.318 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG run test -d /image
2023-08-01 08:11:32.434 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG run touch /image/2_8_san_image.raw.Ki9jn00pCq
2023-08-01 08:11:32.555 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG make_temp tmp: /image/2_8_san_image.raw.Ki9jn00pCq make_temp data: None
2023-08-01 08:11:32.556 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG Starting new HTTP connection (1): consul:8500
2023-08-01 08:11:32.557 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG http://consul:8500 "PUT /v1/kv/task_manager/progress/18287?acquire=62cdbd81-1d49-6dd8-8494-5ff094bc4ba4 HTTP/1.1" 200 29
2023-08-01 08:11:32.557 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG Check task abort job
2023-08-01 08:11:32.582 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG run qemu-img info --force-share --output=json '/dev/Network_lvm_dev_sda/11_san'
2023-08-01 08:11:32.678 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG Image size: 10737418240 bytes
2023-08-01 08:11:32.678 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG run df --output=size,avail --block-size=1 '/image'
2023-08-01 08:11:32.799 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG Directory size: 31366270976 bytes
2023-08-01 08:11:32.799 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG Space available: 20833959936 bytes
2023-08-01 08:11:32.824 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG run qemu-img convert -f raw -O raw '/dev/Network_lvm_dev_sda/11_san_snapshot' '/image/2_8_san_image.raw.Ki9jn00pCq'
2023-08-01 08:12:00.794 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG http://consul:8500 "PUT /v1/session/renew/62cdbd81-1d49-6dd8-8494-5ff094bc4ba4 HTTP/1.1" 200 213
2023-08-01 08:12:30.816 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG http://consul:8500 "PUT /v1/session/renew/62cdbd81-1d49-6dd8-8494-5ff094bc4ba4 HTTP/1.1" 200 213
2023-08-01 08:13:00.844 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG http://consul:8500 "PUT /v1/session/renew/62cdbd81-1d49-6dd8-8494-5ff094bc4ba4 HTTP/1.1" 200 213
2023-08-01 08:13:30.864 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG http://consul:8500 "PUT /v1/session/renew/62cdbd81-1d49-6dd8-8494-5ff094bc4ba4 HTTP/1.1" 200 213
2023-08-01 08:13:30.871 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG http://consul:8500 "PUT /v1/kv/task_manager/progress/18287?acquire=62cdbd81-1d49-6dd8-8494-5ff094bc4ba4 HTTP/1.1" 200 29
2023-08-01 08:13:30.871 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG run mv '/image/2_8_san_image.raw.Ki9jn00pCq' '/image/2_8_san_image.raw'
2023-08-01 08:13:30.950 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG run virt-filesystems --partitions -a /image/2_8_san_image.raw
2023-08-01 08:13:31.093 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] ERROR virt-filesystems --partitions -a /image/2_8_san_image.raw failed with code 1 stderr "libguestfs: error: qemu-img: /tmp/libguestfsa9AAQV/overlay1.qcow2: qemu-img exited with error status 1.
To see full error messages you may need to enable debugging.
Do:
  export LIBGUESTFS_DEBUG=1 LIBGUESTFS_TRACE=1
and run the command again.  For further information, read:
  http://libguestfs.org/guestfs-faq.1.html#debugging-libguestfs
You can also run 'libguestfs-test-tool' and post the *complete* output
into a bug report or message to the libguestfs mailing list.
"
2023-08-01 08:13:31.093 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG run virt-sparsify --in-place /image/2_8_san_image.raw
2023-08-01 08:13:34.416 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG Check task abort job
2023-08-01 08:13:34.442 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG run du --block-size=1M /image/2_8_san_image.raw
2023-08-01 08:13:34.536 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG Starting new HTTP connection (1): consul:8500
2023-08-01 08:13:34.537 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG http://consul:8500 "PUT /v1/session/create HTTP/1.1" 200 77
2023-08-01 08:13:34.538 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG [ConsulSession#0593ef73-a4c7-b61e-e581-97aeb36cc864]: session is created
2023-08-01 08:13:34.539 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG http://consul:8500 "PUT /v1/session/renew/0593ef73-a4c7-b61e-e581-97aeb36cc864 HTTP/1.1" 200 232
2023-08-01 08:13:34.540 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG Starting new HTTP connection (1): consul:8500
2023-08-01 08:13:34.541 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG http://consul:8500 "PUT /v1/kv/storage/6/lock?acquire=0593ef73-a4c7-b61e-e581-97aeb36cc864 HTTP/1.1" 200 29
2023-08-01 08:13:34.541 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG [ConsulLock#storage/6/lock#0593ef73-a4c7-b61e-e581-97aeb36cc864]: lock is created
2023-08-01 08:13:34.541 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG run vgscan --cache && lvscan && virsh pool-refresh Network_lvm_dev_sda
2023-08-01 08:13:34.869 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG run dmsetup remove '/dev/Network_lvm_dev_sda/11_san_snapshot'
2023-08-01 08:13:35.011 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG run lvremove -f '/dev/Network_lvm_dev_sda/11_san_snapshot'
2023-08-01 08:13:35.418 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG http://consul:8500 "PUT /v1/kv/storage/6/lock?release=0593ef73-a4c7-b61e-e581-97aeb36cc864 HTTP/1.1" 200 29
2023-08-01 08:13:35.418 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG [ConsulLock#storage/6/lock#0593ef73-a4c7-b61e-e581-97aeb36cc864]: lock is released
2023-08-01 08:13:35.419 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG http://consul:8500 "PUT /v1/session/destroy/0593ef73-a4c7-b61e-e581-97aeb36cc864 HTTP/1.1" 200 29
2023-08-01 08:13:35.419 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG [ConsulSession#0593ef73-a4c7-b61e-e581-97aeb36cc864]: session is destroyed
2023-08-01 08:13:35.420 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] INFO Try connect to http://input:1500/vm/v3/image/2/change_state with headers {'Host': 'instance-1', 'internal-auth': 'on'}
2023-08-01 08:13:35.420 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG Using selector: EpollSelector
2023-08-01 08:13:35.424 [pid=1034] [#df592a90a9ada8cc86d02893f5aa9942/10.60.4.173/@n.mamaev@ispsystem.com] DEBUG Result: {'size_mib': 10240, 'file_size_mib': 1873}