Attachment 665384 Details for Bug 888209 – engine.log

engine.log

engine-redacted.log (text/plain), 15.92 KB, created by Petr Spacek on 2012-12-18 09:47:14 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Petr Spacek

Created: 2012-12-18 09:47:14 UTC

Size: 15.92 KB

patch

obsolete

>2012-12-18 10:17:04,755 INFO  [org.ovirt.engine.core.bll.storage.AttachStorageDomainToPoolCommand] (pool-4-thread-50) [2cecfb36] Running command: AttachStorageDomainToPoolCommand internal: false. Entities affected :  ID: 93281396-002a-474c-be68-d3c00238a92a Type: Storage
>2012-12-18 10:17:04,797 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand] (pool-4-thread-47) [58f80f91] START, ValidateStorageServerConnectionVDSCommand(HostName = laika, HostId = abc800c2-4847-11e2-8033-525400d9cd76, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: ac176875-69c3-4fed-a553-015b6820c14f, connection: laika.example.com:/rhev-iso, iqn: null, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 61eb9938
>2012-12-18 10:17:04,803 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand] (pool-4-thread-46) [561c00c0] START, ValidateStorageServerConnectionVDSCommand(HostName = belka, HostId = a3bab2bc-4847-11e2-aad9-525400d9cd76, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: ac176875-69c3-4fed-a553-015b6820c14f, connection: laika.example.com:/rhev-iso, iqn: null, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 11b67fa7
>2012-12-18 10:17:04,853 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand] (pool-4-thread-47) [58f80f91] FINISH, ValidateStorageServerConnectionVDSCommand, return: {ac176875-69c3-4fed-a553-015b6820c14f=0}, log id: 61eb9938
>2012-12-18 10:17:04,853 INFO  [org.ovirt.engine.core.bll.storage.ConnectStorageToVdsCommand] (pool-4-thread-47) [58f80f91] Running command: ConnectStorageToVdsCommand internal: true. Entities affected :  ID: aaa00000-0000-0000-0000-123456789aaa Type: System
>2012-12-18 10:17:04,856 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (pool-4-thread-47) [58f80f91] START, ConnectStorageServerVDSCommand(HostName = laika, HostId = abc800c2-4847-11e2-8033-525400d9cd76, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: ac176875-69c3-4fed-a553-015b6820c14f, connection: laika.example.com:/rhev-iso, iqn: null, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 53f8d658
>2012-12-18 10:17:04,862 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand] (pool-4-thread-46) [561c00c0] FINISH, ValidateStorageServerConnectionVDSCommand, return: {ac176875-69c3-4fed-a553-015b6820c14f=0}, log id: 11b67fa7
>2012-12-18 10:17:04,862 INFO  [org.ovirt.engine.core.bll.storage.ConnectStorageToVdsCommand] (pool-4-thread-46) [561c00c0] Running command: ConnectStorageToVdsCommand internal: true. Entities affected :  ID: aaa00000-0000-0000-0000-123456789aaa Type: System
>2012-12-18 10:17:04,866 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (pool-4-thread-46) [561c00c0] START, ConnectStorageServerVDSCommand(HostName = belka, HostId = a3bab2bc-4847-11e2-aad9-525400d9cd76, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: ac176875-69c3-4fed-a553-015b6820c14f, connection: laika.example.com:/rhev-iso, iqn: null, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 2484f9ba
>2012-12-18 10:17:04,954 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (pool-4-thread-47) [58f80f91] FINISH, ConnectStorageServerVDSCommand, return: {ac176875-69c3-4fed-a553-015b6820c14f=100}, log id: 53f8d658
>2012-12-18 10:17:04,957 ERROR [org.ovirt.engine.core.bll.storage.NFSStorageHelper] (pool-4-thread-47) [58f80f91] The connection with details laika.example.com:/rhev-iso failed because of error code 100 and error message is: general exception
>2012-12-18 10:17:04,962 ERROR [org.ovirt.engine.core.bll.storage.ConnectStorageToVdsCommand] (pool-4-thread-47) [58f80f91] Transaction rolled-back for command: org.ovirt.engine.core.bll.storage.ConnectStorageToVdsCommand.
>2012-12-18 10:17:04,962 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (pool-4-thread-46) [561c00c0] FINISH, ConnectStorageServerVDSCommand, return: {ac176875-69c3-4fed-a553-015b6820c14f=100}, log id: 2484f9ba
>2012-12-18 10:17:04,968 ERROR [org.ovirt.engine.core.bll.storage.NFSStorageHelper] (pool-4-thread-46) [561c00c0] The connection with details laika.example.com:/rhev-iso failed because of error code 100 and error message is: general exception
>2012-12-18 10:17:04,972 ERROR [org.ovirt.engine.core.bll.storage.ConnectStorageToVdsCommand] (pool-4-thread-46) [561c00c0] Transaction rolled-back for command: org.ovirt.engine.core.bll.storage.ConnectStorageToVdsCommand.
>2012-12-18 10:17:04,973 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand] (pool-4-thread-50) [2cecfb36] START, AttachStorageDomainVDSCommand( storagePoolId = bb2b1888-ac09-41a8-ba53-5b86aa3417a2, ignoreFailoverLimit = false, compatabilityVersion = null, storageDomainId = 93281396-002a-474c-be68-d3c00238a92a), log id: 54284b57
>2012-12-18 10:17:07,295 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-4-thread-50) [2cecfb36] Failed in AttachStorageDomainVDS method
>2012-12-18 10:17:07,296 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-4-thread-50) [2cecfb36] Error code StorageDomainDoesNotExist and error message IRSGenericException: IRSErrorException: Failed to AttachStorageDomainVDS, error = Storage domain does not exist: ('93281396-002a-474c-be68-d3c00238a92a',)
>2012-12-18 10:17:07,296 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (pool-4-thread-50) [2cecfb36] IrsBroker::Failed::AttachStorageDomainVDS due to: IRSErrorException: IRSGenericException: IRSErrorException: Failed to AttachStorageDomainVDS, error = Storage domain does not exist: ('93281396-002a-474c-be68-d3c00238a92a',)
>2012-12-18 10:17:07,362 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (pool-4-thread-50) [2cecfb36] START, SpmStopVDSCommand(HostName = laika, HostId = abc800c2-4847-11e2-8033-525400d9cd76, storagePoolId = bb2b1888-ac09-41a8-ba53-5b86aa3417a2), log id: 65cf2ebd
>2012-12-18 10:17:07,412 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (pool-4-thread-50) [2cecfb36] SpmStopVDSCommand::Stopping SPM on vds laika, pool id bb2b1888-ac09-41a8-ba53-5b86aa3417a2
>2012-12-18 10:17:08,075 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (pool-4-thread-50) [2cecfb36] FINISH, SpmStopVDSCommand, log id: 65cf2ebd
>2012-12-18 10:17:08,075 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (pool-4-thread-50) [2cecfb36] Irs placed on server null failed. Proceed Failover
>2012-12-18 10:17:08,089 INFO  [org.ovirt.engine.core.bll.storage.SetStoragePoolStatusCommand] (pool-4-thread-50) [13f3abd1] Running command: SetStoragePoolStatusCommand internal: true. Entities affected :  ID: bb2b1888-ac09-41a8-ba53-5b86aa3417a2 Type: StoragePool
>2012-12-18 10:17:08,140 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (pool-4-thread-50) [13f3abd1] hostFromVds::selectedVds - belka, spmStatus Free, storage pool IDM_BRQ
>2012-12-18 10:17:08,145 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (pool-4-thread-50) [13f3abd1] starting spm on vds belka, storage pool IDM_BRQ, prevId -1, LVER 0
>2012-12-18 10:17:08,147 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (pool-4-thread-50) [13f3abd1] START, SpmStartVDSCommand(HostName = belka, HostId = a3bab2bc-4847-11e2-aad9-525400d9cd76, storagePoolId = bb2b1888-ac09-41a8-ba53-5b86aa3417a2, prevId=-1, prevLVER=0, storagePoolFormatType=V3, recoveryMode=Manual, SCSIFencing=false), log id: 339a4395
>2012-12-18 10:17:08,179 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (pool-4-thread-50) [13f3abd1] spmStart polling started: taskId = b798078f-681d-4675-b47d-ae6b769a0270
>2012-12-18 10:17:15,475 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (pool-4-thread-50) [13f3abd1] spmStart polling ended: taskId = b798078f-681d-4675-b47d-ae6b769a0270 task status = finished
>2012-12-18 10:17:15,502 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (pool-4-thread-50) [13f3abd1] spmStart polling ended, spm status: SPM
>2012-12-18 10:17:15,505 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-4-thread-50) [13f3abd1] START, HSMClearTaskVDSCommand(HostName = belka, HostId = a3bab2bc-4847-11e2-aad9-525400d9cd76, taskId=b798078f-681d-4675-b47d-ae6b769a0270), log id: 5f8e0ac7
>2012-12-18 10:17:15,532 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-4-thread-50) [13f3abd1] FINISH, HSMClearTaskVDSCommand, log id: 5f8e0ac7
>2012-12-18 10:17:15,532 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (pool-4-thread-50) [13f3abd1] FINISH, SpmStartVDSCommand, return: org.ovirt.engine.core.common.businessentities.SpmStatusResult@6665bfd3, log id: 339a4395
>2012-12-18 10:17:15,558 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (pool-4-thread-50) [13f3abd1] Initialize Irs proxy from vds: belka.example.com
>2012-12-18 10:17:15,592 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-81) [2a6519e4] Attempting to get and stop tasks on storage pool IDM_BRQ
>2012-12-18 10:17:15,594 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetAllTasksInfoVDSCommand] (QuartzScheduler_Worker-81) [2a6519e4] START, SPMGetAllTasksInfoVDSCommand( storagePoolId = bb2b1888-ac09-41a8-ba53-5b86aa3417a2, ignoreFailoverLimit = false, compatabilityVersion = null), log id: 1473614a
>2012-12-18 10:17:15,789 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-4-thread-50) [13f3abd1] Failed in AttachStorageDomainVDS method
>2012-12-18 10:17:15,789 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-4-thread-50) [13f3abd1] Error code StorageDomainDoesNotExist and error message IRSGenericException: IRSErrorException: Failed to AttachStorageDomainVDS, error = Storage domain does not exist: ('93281396-002a-474c-be68-d3c00238a92a',)
>2012-12-18 10:17:15,790 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (pool-4-thread-50) [13f3abd1] IrsBroker::Failed::AttachStorageDomainVDS due to: IRSErrorException: IRSGenericException: IRSErrorException: Failed to AttachStorageDomainVDS, error = Storage domain does not exist: ('93281396-002a-474c-be68-d3c00238a92a',)
>2012-12-18 10:17:15,792 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetAllTasksInfoVDSCommand] (QuartzScheduler_Worker-81) [2a6519e4] -- SPMGetAllTasksInfoVDSCommand::ExecuteIrsBrokerCommand: Attempting on storage pool bb2b1888-ac09-41a8-ba53-5b86aa3417a2
>2012-12-18 10:17:15,793 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand] (pool-4-thread-50) [13f3abd1] FINISH, AttachStorageDomainVDSCommand, log id: 54284b57
>2012-12-18 10:17:15,793 ERROR [org.ovirt.engine.core.bll.storage.AttachStorageDomainToPoolCommand] (pool-4-thread-50) [13f3abd1] Command org.ovirt.engine.core.bll.storage.AttachStorageDomainToPoolCommand throw Vdc Bll exception. With error message VdcBLLException: org.ovirt.engine.core.vdsbroker.irsbroker.IRSErrorException: IRSGenericException: IRSErrorException: Failed to AttachStorageDomainVDS, error = Storage domain does not exist: ('93281396-002a-474c-be68-d3c00238a92a',)
>2012-12-18 10:17:15,795 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksInfoVDSCommand] (QuartzScheduler_Worker-81) [2a6519e4] START, HSMGetAllTasksInfoVDSCommand(HostName = belka, HostId = a3bab2bc-4847-11e2-aad9-525400d9cd76), log id: 71f2758e
>2012-12-18 10:17:15,802 INFO  [org.ovirt.engine.core.bll.storage.AttachStorageDomainToPoolCommand] (pool-4-thread-50) [13f3abd1] Command [id=6165bd8f-e91d-41b8-8af1-201c9911091d]: Compensating NEW_ENTITY_ID of org.ovirt.engine.core.common.businessentities.storage_pool_iso_map; snapshot: storagePoolId = bb2b1888-ac09-41a8-ba53-5b86aa3417a2, storageId = 93281396-002a-474c-be68-d3c00238a92a.
>2012-12-18 10:17:15,847 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksInfoVDSCommand] (QuartzScheduler_Worker-81) [2a6519e4] FINISH, HSMGetAllTasksInfoVDSCommand, return: [], log id: 71f2758e
>2012-12-18 10:17:15,847 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetAllTasksInfoVDSCommand] (QuartzScheduler_Worker-81) [2a6519e4] FINISH, SPMGetAllTasksInfoVDSCommand, return: [], log id: 1473614a
>2012-12-18 10:17:15,847 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-81) [2a6519e4] Discovered no tasks on Storage Pool IDM_BRQ
>2012-12-18 10:17:15,847 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetAllTasksInfoVDSCommand] (QuartzScheduler_Worker-81) [2a6519e4] START, SPMGetAllTasksInfoVDSCommand( storagePoolId = bb2b1888-ac09-41a8-ba53-5b86aa3417a2, ignoreFailoverLimit = false, compatabilityVersion = null), log id: 6727d606
>2012-12-18 10:17:15,848 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetAllTasksInfoVDSCommand] (QuartzScheduler_Worker-81) [2a6519e4] -- SPMGetAllTasksInfoVDSCommand::ExecuteIrsBrokerCommand: Attempting on storage pool bb2b1888-ac09-41a8-ba53-5b86aa3417a2
>2012-12-18 10:17:15,850 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksInfoVDSCommand] (QuartzScheduler_Worker-81) [2a6519e4] START, HSMGetAllTasksInfoVDSCommand(HostName = belka, HostId = a3bab2bc-4847-11e2-aad9-525400d9cd76), log id: 281f5a19
>2012-12-18 10:17:15,899 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksInfoVDSCommand] (QuartzScheduler_Worker-81) [2a6519e4] FINISH, HSMGetAllTasksInfoVDSCommand, return: [], log id: 281f5a19
>2012-12-18 10:17:15,899 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetAllTasksInfoVDSCommand] (QuartzScheduler_Worker-81) [2a6519e4] FINISH, SPMGetAllTasksInfoVDSCommand, return: [], log id: 6727d606
>2012-12-18 10:17:15,899 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-81) [2a6519e4] Discovered no tasks on Storage Pool IDM_BRQ
>2012-12-18 10:20:00,001 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-12) [6f6cbc1f] Checking autorecoverable hosts
>2012-12-18 10:20:00,006 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-12) [6f6cbc1f] Autorecovering 0 hosts
>2012-12-18 10:20:00,006 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-12) [6f6cbc1f] Checking autorecoverable hosts done
>2012-12-18 10:20:00,006 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-12) [6f6cbc1f] Autorecovering storage domains is disabled, skipping
>2012-12-18 10:24:08,592 INFO  [org.ovirt.engine.core.bll.DbUserCacheManager] (QuartzScheduler_Worker-57) [3e9d53e7] DbUserCacheManager::refreshAllUserData() - entered
>2012-12-18 10:25:00,000 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-53) [5434abec] Checking autorecoverable hosts
>2012-12-18 10:25:00,002 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-53) [5434abec] Autorecovering 0 hosts
>2012-12-18 10:25:00,002 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-53) [5434abec] Checking autorecoverable hosts done
>2012-12-18 10:25:00,002 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-53) [5434abec] Autorecovering storage domains is disabled, skipping
>2012-12-18 10:30:00,001 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-7) [27189aa3] Checking autorecoverable hosts
>2012-12-18 10:30:00,003 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-7) [27189aa3] Autorecovering 0 hosts
>2012-12-18 10:30:00,003 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-7) [27189aa3] Checking autorecoverable hosts done
>2012-12-18 10:30:00,003 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-7) [27189aa3] Autorecovering storage domains is disabled, skipping

Actions: View

Attachments on bug 888209: 665384