2022-04-19 10:04:43.253 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] INFO Checking available space on node for backup
2022-04-19 10:04:43.254 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] INFO Try connect to http://input:1500/vm/v3/node/20/storage/6/connect_params with headers {'Host': 'instance-1', 'internal-auth': 'on'}
2022-04-19 10:04:43.255 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG Starting new HTTP connection (1): input:1500
2022-04-19 10:04:43.258 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG http://input:1500 "GET /vm/v3/node/20/storage/6/connect_params HTTP/1.1" 200 174
2022-04-19 10:04:43.259 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run mkdir -m0755 -p /vm
2022-04-19 10:04:43.325 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run df --output=size,avail --block-size=1 '/vm'
2022-04-19 10:04:43.410 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG Stop domain 45_windows
2022-04-19 10:04:43.411 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG Starting new HTTP connection (1): consul:8500
2022-04-19 10:04:43.412 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG http://consul:8500 "PUT /v1/kv/keepalive/instance/1/task/404815993 HTTP/1.1" 200 29
2022-04-19 10:04:43.428 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG Shutdown... try 1
2022-04-19 10:04:46.443 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG Shutdown... try 2
2022-04-19 10:04:49.458 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG Shutdown... try 3
2022-04-19 10:04:52.472 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG Shutdown... try 4
2022-04-19 10:04:55.481 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG Shutdown... try 5
2022-04-19 10:04:58.489 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG Shutdown... try 6
2022-04-19 10:05:01.512 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG http://consul:8500 "PUT /v1/kv/keepalive/instance/1/task/404815993 HTTP/1.1" 200 29
2022-04-19 10:05:01.532 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] INFO Installing qemu-guest-agent
2022-04-19 10:05:01.532 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run (. /etc/os-release ; echo $ID-$VERSION_ID)
2022-04-19 10:05:01.554 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run which zstd
2022-04-19 10:05:01.621 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] INFO Creating backup of windows
2022-04-19 10:05:01.623 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG http://consul:8500 "PUT /v1/kv/keepalive/instance/1/task/404815993 HTTP/1.1" 200 29
2022-04-19 10:05:01.629 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG Check task abort job
2022-04-19 10:05:01.629 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run qemu-img info --force-share --output=json '/vm/52_windows'
2022-04-19 10:05:01.694 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG Image size: 15057080320 bytes
2022-04-19 10:05:01.694 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run df --output=size,avail --block-size=1 '/image'
2022-04-19 10:05:01.765 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG Directory size: 85884469248 bytes
2022-04-19 10:05:01.765 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG Space available: 48969138176 bytes
2022-04-19 10:05:01.771 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run nproc | tr -d '
2022-04-19 10:05:01.835 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run set -o pipefail; nice -n 5 dd bs=4M if=/vm/52_windows | zstd --no-progress --rm -1 -T2 -c | dd bs=4M of=/image/52_52_windows_disk_guest_agent_backup.zst
2022-04-19 10:10:59.614 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG Check task abort job
2022-04-19 10:10:59.615 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run du --block-size=1M /image/52_52_windows_disk_guest_agent_backup.zst
2022-04-19 10:10:59.627 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG Set link params: target_bus virtio target_dev vda boot_order 1
2022-04-19 10:10:59.627 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] INFO Retriving needed utils to install qemu-guest-agent
2022-04-19 10:10:59.627 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run test -d /usr/share/virt-tools
2022-04-19 10:10:59.712 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] ERROR test -d /usr/share/virt-tools failed with code 1 stderr ""
2022-04-19 10:10:59.712 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run mkdir -p /usr/share/virt-tools
2022-04-19 10:10:59.765 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run test -d /opt/ispsystem/windows_ga/vmmgr
2022-04-19 10:10:59.816 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] ERROR test -d /opt/ispsystem/windows_ga/vmmgr failed with code 1 stderr ""
2022-04-19 10:10:59.816 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run mkdir -p /opt/ispsystem/windows_ga/vmmgr
2022-04-19 10:10:59.867 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run test -f /usr/share/virt-tools/rhsrvany.exe
2022-04-19 10:10:59.923 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] ERROR test -f /usr/share/virt-tools/rhsrvany.exe failed with code 1 stderr ""
2022-04-19 10:10:59.923 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] INFO Copying rhsrvany.exe
2022-04-19 10:11:01.513 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run test -f /opt/ispsystem/windows_ga/vmmgr/redhat.crt.p7b
2022-04-19 10:11:01.524 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] ERROR test -f /opt/ispsystem/windows_ga/vmmgr/redhat.crt.p7b failed with code 1 stderr ""
2022-04-19 10:11:01.524 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] INFO Copying redhat.crt.p7b
2022-04-19 10:11:01.581 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run test -f /opt/ispsystem/windows_ga/vmmgr/virtio.cmd
2022-04-19 10:11:01.592 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] ERROR test -f /opt/ispsystem/windows_ga/vmmgr/virtio.cmd failed with code 1 stderr ""
2022-04-19 10:11:01.593 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] INFO Copying virtio.cmd
2022-04-19 10:11:01.649 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run test -f /opt/ispsystem/windows_ga/vmmgr/virtio-win-guest-tools.exe
2022-04-19 10:11:01.660 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] ERROR test -f /opt/ispsystem/windows_ga/vmmgr/virtio-win-guest-tools.exe failed with code 1 stderr ""
2022-04-19 10:11:01.660 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] INFO Copying virtio-win-guest-tools.exe
2022-04-19 10:11:03.877 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] INFO Changing disk bus to ide
2022-04-19 10:11:03.916 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] INFO Copying windows qemu-guest-agent files
2022-04-19 10:11:03.916 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run LIBGUESTFS_BACKEND=direct LIBGUESTFS_MEMSIZE=512 virt-copy-in -a /vm/52_windows /opt/ispsystem/windows_ga/vmmgr/ /
2022-04-19 10:11:18.232 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] ERROR LIBGUESTFS_BACKEND=direct LIBGUESTFS_MEMSIZE=512 virt-copy-in -a /vm/52_windows /opt/ispsystem/windows_ga/vmmgr/ / failed with code 1 stderr "libguestfs: error: inspect_os: sgdisk: Caution: invalid backup GPT header, but valid main header; regenerating
2022-04-19 10:11:18.232 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] INFO Can't copy files, zapping GPT from /vm/52_windows and fixing NTFS
2022-04-19 10:11:18.232 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run LIBGUESTFS_MEMSIZE=512 guestfish << EOF
2022-04-19 10:11:21.962 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] ERROR LIBGUESTFS_MEMSIZE=512 guestfish << EOF
2022-04-19 10:11:21.962 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] ERROR failed to install qemu guest agent: Copying windows qemu-guest-agent files was failed. Error: *stdin*:4: libguestfs: error: command: Caution: invalid backup GPT header, but valid main header; regenerating
2022-04-19 10:11:21.962 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] INFO restoring VM's disk
2022-04-19 10:11:21.962 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run nice -n 5 zstd --no-progress -d /image/52_52_windows_disk_guest_agent_backup.zst
2022-04-19 10:15:30.353 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] INFO extract image to volume
2022-04-19 10:15:30.354 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run LIBGUESTFS_BACKEND=direct /usr/bin/virt-resize --format 'raw' --output-format 'qcow2' --expand /dev/sda2 /image/52_52_windows_disk_guest_agent_backup /vm/52_windows
2022-04-19 10:15:34.023 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] ERROR LIBGUESTFS_BACKEND=direct /usr/bin/virt-resize --format 'raw' --output-format 'qcow2' --expand /dev/sda2 /image/52_52_windows_disk_guest_agent_backup /vm/52_windows failed with code 1 stderr "virt-resize: error: You cannot use --expand when there is no surplus space
2022-04-19 10:15:34.023 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run LIBGUESTFS_BACKEND=direct /usr/bin/virt-resize --format 'raw' --output-format 'qcow2' --shrink /dev/sda2 /image/52_52_windows_disk_guest_agent_backup /vm/52_windows
2022-04-19 10:15:36.188 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] ERROR LIBGUESTFS_BACKEND=direct /usr/bin/virt-resize --format 'raw' --output-format 'qcow2' --shrink /dev/sda2 /image/52_52_windows_disk_guest_agent_backup /vm/52_windows failed with code 1 stderr "virt-resize: error: /dev/sda2: This partition contains a ntfs filesystem
2022-04-19 10:15:36.189 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run /usr/bin/qemu-img convert -O qcow2 /image/52_52_windows_disk_guest_agent_backup /vm/52_windows && /usr/bin/qemu-img resize /vm/52_windows 20480M && virsh pool-refresh --pool File_vm
2022-04-19 10:20:56.880 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run rm -rf /image/52_52_windows_disk_guest_agent_backup
2022-04-19 10:20:57.218 [pid=11901] [#7f6f48b19f07f4f4f6de6e38abd7ef81/172.19.0.10/@[e-mail]] DEBUG run rm -rf /image/52_52_windows_disk_guest_agent_backup.zst