Attachment 1449919 Details for Bug 1589687 – engine log

engine log

engine.log (text/plain), 29.72 KB, created by Yosi Ben Shimon on 2018-06-11 08:03:07 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Yosi Ben Shimon

Created: 2018-06-11 08:03:07 UTC

Size: 29.72 KB

patch

obsolete

>2018-06-11 10:37:22,514+03 INFO  [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks.
>2018-06-11 10:37:22,515+03 INFO  [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 24 threads waiting for tasks and 0 tasks in queue.
>2018-06-11 10:37:22,515+03 INFO  [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100 threads waiting for tasks.
>2018-06-11 10:37:22,515+03 INFO  [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks.
>2018-06-11 10:41:00,192+03 INFO  [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-24) [799be601] Lock Acquired to object 'EngineLock:{exclusiveLocks='[84e45180-1598-47b1-87c3-e6bf0e251d2d=PROVIDER]', sharedLocks=''}'
>2018-06-11 10:41:00,218+03 INFO  [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-24) [799be601] Running command: SyncNetworkProviderCommand internal: true.
>2018-06-11 10:41:00,569+03 INFO  [org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default task-11) [] User admin@internal successfully logged in with scopes: ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:public-authz-search ovirt-ext=token-info:validate ovirt-ext=token:password-access
>2018-06-11 10:41:00,874+03 INFO  [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-24) [799be601] Lock freed to object 'EngineLock:{exclusiveLocks='[84e45180-1598-47b1-87c3-e6bf0e251d2d=PROVIDER]', sharedLocks=''}'
>2018-06-11 10:41:24,176+03 INFO  [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (default task-10) [2b7e121f-d8e7-489a-aac0-d803162529f0] Lock Acquired to object 'EngineLock:{exclusiveLocks='', sharedLocks='[5b06e86f-6e65-4fb0-89e9-fc995dd35b6a=DISK]'}'
>2018-06-11 10:41:24,332+03 INFO  [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (default task-10) [2b7e121f-d8e7-489a-aac0-d803162529f0] Running command: TransferDiskImageCommand internal: false. Entities affected :  ID: 5b06e86f-6e65-4fb0-89e9-fc995dd35b6a Type: DiskAction group EDIT_DISK_PROPERTIES with role type USER
>2018-06-11 10:41:24,332+03 INFO  [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (default task-10) [2b7e121f-d8e7-489a-aac0-d803162529f0] Creating ImageTransfer entity for command 'bece07d8-aeb1-42bf-b80f-1fff6a8aa039'
>2018-06-11 10:41:24,359+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (default task-10) [2b7e121f-d8e7-489a-aac0-d803162529f0] START, GetVolumeInfoVDSCommand(HostName = host_mixed_1, GetVolumeInfoVDSCommandParameters:{hostId='2d634e08-1d85-4738-83ba-b709a1b0479d', storagePoolId='a3e12471-412f-4152-bee1-280b1986383b', storageDomainId='9962ce15-6d86-4455-86ae-5907fdf5c50d', imageGroupId='5b06e86f-6e65-4fb0-89e9-fc995dd35b6a', imageId='c60a1e4c-d75c-461d-85db-4e68560dd91a'}), log id: 292c684
>2018-06-11 10:41:24,818+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (default task-10) [2b7e121f-d8e7-489a-aac0-d803162529f0] FINISH, GetVolumeInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.DiskImage@42c17620, log id: 292c684
>2018-06-11 10:41:24,827+03 INFO  [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (default task-10) [2b7e121f-d8e7-489a-aac0-d803162529f0] Successfully added Download disk 'test' (disk id: '5b06e86f-6e65-4fb0-89e9-fc995dd35b6a', image id: 'c60a1e4c-d75c-461d-85db-4e68560dd91a') for image transfer command 'bece07d8-aeb1-42bf-b80f-1fff6a8aa039'
>2018-06-11 10:41:24,900+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.PrepareImageVDSCommand] (default task-10) [2b7e121f-d8e7-489a-aac0-d803162529f0] START, PrepareImageVDSCommand(HostName = host_mixed_2, PrepareImageVDSCommandParameters:{hostId='7cbb5c90-c9f2-402e-ab39-0127232932d2'}), log id: 6ef029df
>2018-06-11 10:41:26,041+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.PrepareImageVDSCommand] (default task-10) [2b7e121f-d8e7-489a-aac0-d803162529f0] FINISH, PrepareImageVDSCommand, return: PrepareImageReturn:{status='Status [code=0, message=Done]'}, log id: 6ef029df
>2018-06-11 10:41:26,050+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.AddImageTicketVDSCommand] (default task-10) [2b7e121f-d8e7-489a-aac0-d803162529f0] START, AddImageTicketVDSCommand(HostName = host_mixed_2, AddImageTicketVDSCommandParameters:{hostId='7cbb5c90-c9f2-402e-ab39-0127232932d2', ticketId='a8817168-3507-4529-a2a2-ed63acd4b97a', timeout='300', operations='[read]', size='1073741824', url='file:///rhev/data-center/mnt/blockSD/9962ce15-6d86-4455-86ae-5907fdf5c50d/images/5b06e86f-6e65-4fb0-89e9-fc995dd35b6a/c60a1e4c-d75c-461d-85db-4e68560dd91a', filename='test.qcow2'}), log id: 30be7f8b
>2018-06-11 10:41:26,073+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.AddImageTicketVDSCommand] (default task-10) [2b7e121f-d8e7-489a-aac0-d803162529f0] FINISH, AddImageTicketVDSCommand, return: StatusOnlyReturn [status=Status [code=0, message=Done]], log id: 30be7f8b
>2018-06-11 10:41:26,073+03 INFO  [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (default task-10) [2b7e121f-d8e7-489a-aac0-d803162529f0] Started transfer session with ticket id a8817168-3507-4529-a2a2-ed63acd4b97a, timeout 300 seconds
>2018-06-11 10:41:26,073+03 INFO  [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (default task-10) [2b7e121f-d8e7-489a-aac0-d803162529f0] Adding image ticket to ovirt-imageio-proxy, id a8817168-3507-4529-a2a2-ed63acd4b97a
>2018-06-11 10:41:26,130+03 INFO  [org.ovirt.engine.core.bll.storage.disk.image.ImageTransferUpdater] (default task-10) [2b7e121f-d8e7-489a-aac0-d803162529f0] Updating image transfer bece07d8-aeb1-42bf-b80f-1fff6a8aa039 (image 5b06e86f-6e65-4fb0-89e9-fc995dd35b6a) phase to Transferring
>2018-06-11 10:41:26,134+03 INFO  [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (default task-10) [2b7e121f-d8e7-489a-aac0-d803162529f0] Returning from proceedCommandExecution after starting transfer session for image transfer command 'bece07d8-aeb1-42bf-b80f-1fff6a8aa039'
>2018-06-11 10:41:26,155+03 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-10) [2b7e121f-d8e7-489a-aac0-d803162529f0] EVENT_ID: TRANSFER_IMAGE_INITIATED(1,031), Image Download with disk test was initiated by admin@internal-authz.
>2018-06-11 10:41:27,302+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-89) [2b7e121f-d8e7-489a-aac0-d803162529f0] START, GetImageTicketVDSCommand(HostName = host_mixed_2, GetImageTicketVDSCommandParameters:{hostId='7cbb5c90-c9f2-402e-ab39-0127232932d2', ticketId='a8817168-3507-4529-a2a2-ed63acd4b97a', timeout='null'}), log id: 47c4a9b8
>2018-06-11 10:41:27,335+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-89) [2b7e121f-d8e7-489a-aac0-d803162529f0] FINISH, GetImageTicketVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.ImageTicketInformation@5c4ec130, log id: 47c4a9b8
>2018-06-11 10:41:31,372+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-100) [2b7e121f-d8e7-489a-aac0-d803162529f0] START, GetImageTicketVDSCommand(HostName = host_mixed_2, GetImageTicketVDSCommandParameters:{hostId='7cbb5c90-c9f2-402e-ab39-0127232932d2', ticketId='a8817168-3507-4529-a2a2-ed63acd4b97a', timeout='null'}), log id: 7e336cfc
>2018-06-11 10:41:31,398+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-100) [2b7e121f-d8e7-489a-aac0-d803162529f0] FINISH, GetImageTicketVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.ImageTicketInformation@557b5eb8, log id: 7e336cfc
>2018-06-11 10:41:39,528+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-74) [2b7e121f-d8e7-489a-aac0-d803162529f0] START, GetImageTicketVDSCommand(HostName = host_mixed_2, GetImageTicketVDSCommandParameters:{hostId='7cbb5c90-c9f2-402e-ab39-0127232932d2', ticketId='a8817168-3507-4529-a2a2-ed63acd4b97a', timeout='null'}), log id: 285978ce
>2018-06-11 10:41:39,550+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-74) [2b7e121f-d8e7-489a-aac0-d803162529f0] FINISH, GetImageTicketVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.ImageTicketInformation@47d499c8, log id: 285978ce
>2018-06-11 10:41:49,603+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-100) [2b7e121f-d8e7-489a-aac0-d803162529f0] START, GetImageTicketVDSCommand(HostName = host_mixed_2, GetImageTicketVDSCommandParameters:{hostId='7cbb5c90-c9f2-402e-ab39-0127232932d2', ticketId='a8817168-3507-4529-a2a2-ed63acd4b97a', timeout='null'}), log id: 78e4461b
>2018-06-11 10:41:49,628+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-100) [2b7e121f-d8e7-489a-aac0-d803162529f0] FINISH, GetImageTicketVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.ImageTicketInformation@36c4239c, log id: 78e4461b
>2018-06-11 10:41:59,672+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-9) [2b7e121f-d8e7-489a-aac0-d803162529f0] START, GetImageTicketVDSCommand(HostName = host_mixed_2, GetImageTicketVDSCommandParameters:{hostId='7cbb5c90-c9f2-402e-ab39-0127232932d2', ticketId='a8817168-3507-4529-a2a2-ed63acd4b97a', timeout='null'}), log id: 799e5d19
>2018-06-11 10:41:59,696+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-9) [2b7e121f-d8e7-489a-aac0-d803162529f0] FINISH, GetImageTicketVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.ImageTicketInformation@25b3ad70, log id: 799e5d19
>2018-06-11 10:42:09,746+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-22) [2b7e121f-d8e7-489a-aac0-d803162529f0] START, GetImageTicketVDSCommand(HostName = host_mixed_2, GetImageTicketVDSCommandParameters:{hostId='7cbb5c90-c9f2-402e-ab39-0127232932d2', ticketId='a8817168-3507-4529-a2a2-ed63acd4b97a', timeout='null'}), log id: 10319cce
>2018-06-11 10:42:09,777+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-22) [2b7e121f-d8e7-489a-aac0-d803162529f0] FINISH, GetImageTicketVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.ImageTicketInformation@14a33744, log id: 10319cce
>2018-06-11 10:42:19,832+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [2b7e121f-d8e7-489a-aac0-d803162529f0] START, GetImageTicketVDSCommand(HostName = host_mixed_2, GetImageTicketVDSCommandParameters:{hostId='7cbb5c90-c9f2-402e-ab39-0127232932d2', ticketId='a8817168-3507-4529-a2a2-ed63acd4b97a', timeout='null'}), log id: 4bcd8042
>2018-06-11 10:42:19,855+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [2b7e121f-d8e7-489a-aac0-d803162529f0] FINISH, GetImageTicketVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.ImageTicketInformation@392c118, log id: 4bcd8042
>2018-06-11 10:42:29,907+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-42) [2b7e121f-d8e7-489a-aac0-d803162529f0] START, GetImageTicketVDSCommand(HostName = host_mixed_2, GetImageTicketVDSCommandParameters:{hostId='7cbb5c90-c9f2-402e-ab39-0127232932d2', ticketId='a8817168-3507-4529-a2a2-ed63acd4b97a', timeout='null'}), log id: 60f69180
>2018-06-11 10:42:29,930+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-42) [2b7e121f-d8e7-489a-aac0-d803162529f0] FINISH, GetImageTicketVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.ImageTicketInformation@f2824aec, log id: 60f69180
>2018-06-11 10:42:29,967+03 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-42) [2b7e121f-d8e7-489a-aac0-d803162529f0] EVENT_ID: DOWNLOAD_IMAGE_CANCELED_TIMEOUT(1,072), Download was canceled by system. Reason: timeout due to transfer inactivity.
>2018-06-11 10:42:29,979+03 INFO  [org.ovirt.engine.core.bll.storage.disk.image.ImageTransferUpdater] (EE-ManagedThreadFactory-engineScheduled-Thread-42) [2b7e121f-d8e7-489a-aac0-d803162529f0] Updating image transfer bece07d8-aeb1-42bf-b80f-1fff6a8aa039 (image 5b06e86f-6e65-4fb0-89e9-fc995dd35b6a) phase to Cancelled
>2018-06-11 10:42:40,048+03 INFO  [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-89) [2b7e121f-d8e7-489a-aac0-d803162529f0] Transfer cancelled for Download disk 'test' (disk id: '5b06e86f-6e65-4fb0-89e9-fc995dd35b6a', image id: 'c60a1e4c-d75c-461d-85db-4e68560dd91a')
>2018-06-11 10:42:40,052+03 INFO  [org.ovirt.engine.core.bll.storage.disk.image.ImageTransferUpdater] (EE-ManagedThreadFactory-engineScheduled-Thread-89) [2b7e121f-d8e7-489a-aac0-d803162529f0] Updating image transfer bece07d8-aeb1-42bf-b80f-1fff6a8aa039 (image 5b06e86f-6e65-4fb0-89e9-fc995dd35b6a) phase to Finalizing Failure
>2018-06-11 10:42:50,164+03 ERROR [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-69) [2b7e121f-d8e7-489a-aac0-d803162529f0] Finalizing failed transfer. Download disk 'test' (disk id: '5b06e86f-6e65-4fb0-89e9-fc995dd35b6a', image id: 'c60a1e4c-d75c-461d-85db-4e68560dd91a')
>2018-06-11 10:42:50,171+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.RemoveImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-69) [2b7e121f-d8e7-489a-aac0-d803162529f0] START, RemoveImageTicketVDSCommand(HostName = host_mixed_2, RemoveImageTicketVDSCommandParameters:{hostId='7cbb5c90-c9f2-402e-ab39-0127232932d2', ticketId='a8817168-3507-4529-a2a2-ed63acd4b97a', timeout='null'}), log id: 199b370f
>2018-06-11 10:42:50,204+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.RemoveImageTicketVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-69) [2b7e121f-d8e7-489a-aac0-d803162529f0] FINISH, RemoveImageTicketVDSCommand, return: StatusOnlyReturn [status=Status [code=0, message=Done]], log id: 199b370f
>2018-06-11 10:42:50,204+03 INFO  [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-69) [2b7e121f-d8e7-489a-aac0-d803162529f0] Successfully stopped image transfer session for ticket 'a8817168-3507-4529-a2a2-ed63acd4b97a'
>2018-06-11 10:42:50,204+03 INFO  [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-69) [2b7e121f-d8e7-489a-aac0-d803162529f0] Removing image ticket from ovirt-imageio-proxy, id a8817168-3507-4529-a2a2-ed63acd4b97a
>2018-06-11 10:42:50,319+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.TeardownImageVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-69) [2b7e121f-d8e7-489a-aac0-d803162529f0] START, TeardownImageVDSCommand(HostName = host_mixed_2, ImageActionsVDSCommandParameters:{hostId='7cbb5c90-c9f2-402e-ab39-0127232932d2'}), log id: 1c5d81e7
>2018-06-11 10:42:51,034+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.TeardownImageVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-69) [2b7e121f-d8e7-489a-aac0-d803162529f0] FINISH, TeardownImageVDSCommand, return: StatusReturn:{status='Status [code=0, message=Done]'}, log id: 1c5d81e7
>2018-06-11 10:42:51,039+03 INFO  [org.ovirt.engine.core.bll.storage.disk.image.ImageTransferUpdater] (EE-ManagedThreadFactory-engineScheduled-Thread-69) [2b7e121f-d8e7-489a-aac0-d803162529f0] Updating image transfer bece07d8-aeb1-42bf-b80f-1fff6a8aa039 (image 5b06e86f-6e65-4fb0-89e9-fc995dd35b6a) phase to Finished Failure
>2018-06-11 10:43:01,082+03 ERROR [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [2b7e121f-d8e7-489a-aac0-d803162529f0] Transfer failed. Download disk 'test' (disk id: '5b06e86f-6e65-4fb0-89e9-fc995dd35b6a', image id: 'c60a1e4c-d75c-461d-85db-4e68560dd91a')
>2018-06-11 10:43:02,104+03 INFO  [org.ovirt.engine.core.bll.storage.disk.image.ImageTransferUpdater] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [2b7e121f-d8e7-489a-aac0-d803162529f0] Updating image transfer bece07d8-aeb1-42bf-b80f-1fff6a8aa039 (image 5b06e86f-6e65-4fb0-89e9-fc995dd35b6a) phase to Finished Failure
>2018-06-11 10:43:02,112+03 ERROR [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [2b7e121f-d8e7-489a-aac0-d803162529f0] Failed to transfer disk '00000000-0000-0000-0000-000000000000' (command id 'bece07d8-aeb1-42bf-b80f-1fff6a8aa039')
>2018-06-11 10:43:02,120+03 INFO  [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [2b7e121f-d8e7-489a-aac0-d803162529f0] Ending command 'org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand' successfully.
>2018-06-11 10:43:02,121+03 INFO  [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [2b7e121f-d8e7-489a-aac0-d803162529f0] Lock freed to object 'EngineLock:{exclusiveLocks='', sharedLocks='[5b06e86f-6e65-4fb0-89e9-fc995dd35b6a=DISK]'}'
>2018-06-11 10:43:02,148+03 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [2b7e121f-d8e7-489a-aac0-d803162529f0] EVENT_ID: TRANSFER_IMAGE_CANCELLED(1,033), Image Download with disk test was cancelled.
>2018-06-11 10:46:00,915+03 INFO  [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [47f7a2de] Lock Acquired to object 'EngineLock:{exclusiveLocks='[84e45180-1598-47b1-87c3-e6bf0e251d2d=PROVIDER]', sharedLocks=''}'
>2018-06-11 10:46:00,943+03 INFO  [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [47f7a2de] Running command: SyncNetworkProviderCommand internal: true.
>2018-06-11 10:46:01,255+03 INFO  [org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default task-7) [] User admin@internal successfully logged in with scopes: ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:public-authz-search ovirt-ext=token-info:validate ovirt-ext=token:password-access
>2018-06-11 10:46:01,642+03 INFO  [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [47f7a2de] Lock freed to object 'EngineLock:{exclusiveLocks='[84e45180-1598-47b1-87c3-e6bf0e251d2d=PROVIDER]', sharedLocks=''}'
>2018-06-11 10:47:22,519+03 INFO  [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks.
>2018-06-11 10:47:22,519+03 INFO  [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 24 threads waiting for tasks and 0 tasks in queue.
>2018-06-11 10:47:22,520+03 INFO  [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100 threads waiting for tasks.
>2018-06-11 10:47:22,520+03 INFO  [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks.
>2018-06-11 10:51:01,678+03 INFO  [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-74) [332fb3c2] Lock Acquired to object 'EngineLock:{exclusiveLocks='[84e45180-1598-47b1-87c3-e6bf0e251d2d=PROVIDER]', sharedLocks=''}'
>2018-06-11 10:51:01,705+03 INFO  [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-74) [332fb3c2] Running command: SyncNetworkProviderCommand internal: true.
>2018-06-11 10:51:02,131+03 INFO  [org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default task-4) [] User admin@internal successfully logged in with scopes: ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:public-authz-search ovirt-ext=token-info:validate ovirt-ext=token:password-access
>2018-06-11 10:51:02,477+03 INFO  [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-74) [332fb3c2] Lock freed to object 'EngineLock:{exclusiveLocks='[84e45180-1598-47b1-87c3-e6bf0e251d2d=PROVIDER]', sharedLocks=''}'
>2018-06-11 10:56:02,511+03 INFO  [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-80) [67d943bf] Lock Acquired to object 'EngineLock:{exclusiveLocks='[84e45180-1598-47b1-87c3-e6bf0e251d2d=PROVIDER]', sharedLocks=''}'
>2018-06-11 10:56:02,538+03 INFO  [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-80) [67d943bf] Running command: SyncNetworkProviderCommand internal: true.
>2018-06-11 10:56:02,957+03 INFO  [org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default task-5) [] User admin@internal successfully logged in with scopes: ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:public-authz-search ovirt-ext=token-info:validate ovirt-ext=token:password-access
>2018-06-11 10:56:03,306+03 INFO  [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-80) [67d943bf] Lock freed to object 'EngineLock:{exclusiveLocks='[84e45180-1598-47b1-87c3-e6bf0e251d2d=PROVIDER]', sharedLocks=''}'
>2018-06-11 10:57:20,002+03 WARN  [org.ovirt.engine.core.utils.servlet.ServletUtils] (default task-6) [] File '/usr/share/ovirt-engine/ui-plugins/dashboard-resources/css/main-tab.8b2085f7.css' is 1396817 bytes long. Please reconsider using this servlet for files larger than 1048576 bytes.
>2018-06-11 10:57:22,526+03 INFO  [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks.
>2018-06-11 10:57:22,526+03 INFO  [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 24 threads waiting for tasks and 0 tasks in queue.
>2018-06-11 10:57:22,526+03 INFO  [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100 threads waiting for tasks.
>2018-06-11 10:57:22,526+03 INFO  [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks.
>2018-06-11 10:58:30,449+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.OvfDataUpdater] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [] Attempting to update VMs/Templates Ovf.
>2018-06-11 10:58:30,468+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [70ad137d] Before acquiring and wait lock 'EngineLock:{exclusiveLocks='[a3e12471-412f-4152-bee1-280b1986383b=OVF_UPDATE]', sharedLocks=''}'
>2018-06-11 10:58:30,468+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [70ad137d] Lock-wait acquired to object 'EngineLock:{exclusiveLocks='[a3e12471-412f-4152-bee1-280b1986383b=OVF_UPDATE]', sharedLocks=''}'
>2018-06-11 10:58:30,472+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [70ad137d] Running command: ProcessOvfUpdateForStoragePoolCommand internal: true. Entities affected :  ID: a3e12471-412f-4152-bee1-280b1986383b Type: StoragePool
>2018-06-11 10:58:30,501+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [70ad137d] Attempting to update VM OVFs in Data Center 'golden_env_mixed'
>2018-06-11 10:58:30,514+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [70ad137d] Successfully updated VM OVFs in Data Center 'golden_env_mixed'
>2018-06-11 10:58:30,514+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [70ad137d] Attempting to update template OVFs in Data Center 'golden_env_mixed'
>2018-06-11 10:58:30,520+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [70ad137d] Successfully updated templates OVFs in Data Center 'golden_env_mixed'
>2018-06-11 10:58:30,520+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [70ad137d] Attempting to remove unneeded template/vm OVFs in Data Center 'golden_env_mixed'
>2018-06-11 10:58:30,541+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [70ad137d] Successfully removed unneeded template/vm OVFs in Data Center 'golden_env_mixed'
>2018-06-11 10:58:30,544+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [70ad137d] Lock freed to object 'EngineLock:{exclusiveLocks='[a3e12471-412f-4152-bee1-280b1986383b=OVF_UPDATE]', sharedLocks=''}'
>2018-06-11 10:58:30,550+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [14b94988] Before acquiring and wait lock 'EngineLock:{exclusiveLocks='[8bc47d51-823a-4a0a-91f1-e00f2bd01b31=OVF_UPDATE]', sharedLocks=''}'
>2018-06-11 10:58:30,551+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [14b94988] Lock-wait acquired to object 'EngineLock:{exclusiveLocks='[8bc47d51-823a-4a0a-91f1-e00f2bd01b31=OVF_UPDATE]', sharedLocks=''}'
>2018-06-11 10:58:30,568+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [14b94988] Running command: ProcessOvfUpdateForStoragePoolCommand internal: true. Entities affected :  ID: 8bc47d51-823a-4a0a-91f1-e00f2bd01b31 Type: StoragePool
>2018-06-11 10:58:30,604+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [14b94988] Attempting to update VM OVFs in Data Center 'test_DC'
>2018-06-11 10:58:30,611+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [14b94988] Successfully updated VM OVFs in Data Center 'test_DC'
>2018-06-11 10:58:30,612+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [14b94988] Attempting to update template OVFs in Data Center 'test_DC'
>2018-06-11 10:58:30,615+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [14b94988] Successfully updated templates OVFs in Data Center 'test_DC'
>2018-06-11 10:58:30,615+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [14b94988] Attempting to remove unneeded template/vm OVFs in Data Center 'test_DC'
>2018-06-11 10:58:30,620+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [14b94988] Successfully removed unneeded template/vm OVFs in Data Center 'test_DC'
>2018-06-11 10:58:30,623+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-87) [14b94988] Lock freed to object 'EngineLock:{exclusiveLocks='[8bc47d51-823a-4a0a-91f1-e00f2bd01b31=OVF_UPDATE]', sharedLocks=''}'
>2018-06-11 10:58:35,686+03 INFO  [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-60) [267bf3b4-c257-4037-82f6-ee3fa3bc4c32] Transfer was paused by system. Upload disk 'aaa' (disk id: '081061d5-c43d-408c-ab70-8979e46a28d7', image id: '568087e0-1294-48f2-9c57-7317fd6a099d')

Actions: View

Attachments on bug 1589687: 1449919 | 1449920