5:09 p.m.
Hi list,
I had to do some fsck-related things last week on my ovirt box (centos,
single node and NFS on localhost).
Afterwards ovirt refused to start VMs according to the webinterface
because it can't connect host to Data Center.
On my OS it works fine (I just replaced the IP by 'IP'):
[root@server ovirt-engine]# df
Filesystem 1K-blocks Used Available Use% Mounted on
/dev/mapper/vg_leiden-lv_root
51606140 6872592 42112108 15% /
tmpfs 3978120 0 3978120 0% /dev/shm
/dev/sdb1 495844 99542 370702 22% /boot
/dev/mapper/vg_server-lv_home
62990260 2584272 57206196 5% /home
/dev/sda1 5814366992 4629615452 1184751540 80% /raid
IP:/raid/ovirt/data
5814367232 4629615616 1184751616 80%
/rhev/data-center/mnt/IP:_raid_ovirt_data
IP:/raid/ovirt/iso
5814367232 4629615616 1184751616 80%
/rhev/data-center/mnt/IP:_raid_ovirt_iso
in my event log in the webinterface I found correlation ID 7a735111 .
So grepping my logs for that one:
engine.log:2014-04-30 15:59:22,851 INFO
[org.ovirt.engine.core.bll.storage.ActivateStorageDomainCommand]
(ajp--127.0.0.1-8702-8) [7a735111] Lock Acquired to object EngineLock
[exclusiveLocks= key: 6bee0e2d-961c-453d-a266-e4623f91e162 value: STORAGE
engine.log:2014-04-30 15:59:22,888 INFO
[org.ovirt.engine.core.bll.storage.ActivateStorageDomainCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] Running command:
ActivateStorageDomainCommand internal: false. Entities affected : ID:
6bee0e2d-961c-453d-a266-e4623f91e162 Type: Storage
engine.log:2014-04-30 15:59:22,894 INFO
[org.ovirt.engine.core.bll.storage.ActivateStorageDomainCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] Lock freed to object
EngineLock [exclusiveLocks= key: 6bee0e2d-961c-453d-a266-e4623f91e162
value: STORAGE
engine.log:2014-04-30 15:59:22,895 INFO
[org.ovirt.engine.core.bll.storage.ActivateStorageDomainCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] ActivateStorage Domain.
Before Connect all hosts to pool. Time:4/30/14 3:59 PM
engine.log:2014-04-30 15:59:22,945 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.ActivateStorageDomainVDSCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] START,
ActivateStorageDomainVDSCommand( storagePoolId =
00000002-0002-0002-0002-0000000000ec, ignoreFailoverLimit = false,
storageDomainId = 6bee0e2d-961c-453d-a266-e4623f91e162), log id: 5fecb439
engine.log:2014-04-30 15:59:23,011 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] hostFromVds::selectedVds
- server, spmStatus Unknown_Pool, storage pool Default
engine.log:2014-04-30 15:59:23,015 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] START,
ConnectStoragePoolVDSCommand(HostName = server, HostId =
ff23de79-f17c-439d-939e-d8f3d9672367, storagePoolId =
00000002-0002-0002-0002-0000000000ec, vds_spm_id = 1, masterDomainId =
6bee0e2d-961c-453d-a266-e4623f91e162, masterVersion = 1), log id: 15866a95
engine.log:2014-04-30 15:59:23,151 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] FINISH,
ConnectStoragePoolVDSCommand, log id: 15866a95
engine.log:2014-04-30 15:59:23,152 ERROR
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111]
IrsBroker::Failed::ActivateStorageDomainVDS due to:
IRSNonOperationalException: IRSGenericException: IRSErrorException:
IRSNonOperationalException: Could not connect host to Data
Center(Storage issue)
engine.log:2014-04-30 15:59:23,156 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.ActivateStorageDomainVDSCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] FINISH,
ActivateStorageDomainVDSCommand, log id: 5fecb439
engine.log:2014-04-30 15:59:23,157 ERROR
[org.ovirt.engine.core.bll.storage.ActivateStorageDomainCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] Command
org.ovirt.engine.core.bll.storage.ActivateStorageDomainCommand throw Vdc
Bll exception. With error message VdcBLLException:
org.ovirt.engine.core.vdsbroker.irsbroker.IRSNonOperationalException:
IRSGenericException: IRSErrorException: IRSNonOperationalException:
Could not connect host to Data Center(Storage issue) (Failed with error
ENGINE and code 5001)
engine.log:2014-04-30 15:59:23,162 INFO
[org.ovirt.engine.core.bll.storage.ActivateStorageDomainCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] Command
[id=c2d8b433-f203-4d9e-b241-222eebf3dbae]: Compensating
CHANGED_STATUS_ONLY of
org.ovirt.engine.core.common.businessentities.StoragePoolIsoMap;
snapshot: EntityStatusSnapshot [id=storagePoolId =
00000002-0002-0002-0002-0000000000ec, storageId =
6bee0e2d-961c-453d-a266-e4623f91e162, status=InActive].
engine.log:2014-04-30 15:59:23,170 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(org.ovirt.thread.pool-6-thread-49) [7a735111] Correlation ID: 7a735111,
Job ID: 75dcda45-e0a3-46e3-b79f-8df9f0ed9d85, Call Stack: null, Custom
Event ID: -1, Message: Failed to activate Storage Domain data (Data
Center Default) by admin
I guess the most relevant error is:
engine.log:2014-04-30 15:59:23,152 ERROR
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111]
IrsBroker::Failed::ActivateStorageDomainVDS due to:
IRSNonOperationalException: IRSGenericException: IRSErrorException:
IRSNonOperationalException: Could not connect host to Data
Center(Storage issue)
Okay so it can't connect to the data center. Well the NFS storage is
mounted and looks fine.
The directory is indeed looking fine:
[root@leiden data]# ls -al
total 12
drwxr-xr-x. 3 vdsm kvm 4096 Mar 30 03:27 .
drwxr-xr-x. 4 vdsm kvm 4096 Mar 30 03:26 ..
drwxr-xr-x. 5 vdsm kvm 4096 Mar 30 03:27
6bee0e2d-961c-453d-a266-e4623f91e162
-rwxr-xr-x. 1 vdsm kvm 0 Mar 30 03:27 __DIRECT_IO_TEST__
(and in the uuid there are indeed my VMs).
How should I solve this? To me everything looks just fine.
Cheers
Boudewijn Ector
8:54 a.m.
New subject: "Could not connect host to Data Center" after rebooting, how to resolve?
Hi,
Could you please attach the vdsm logs for the host for the time around the logs you pasted
from the engine.log?
Thanks,
Gadi Ickowicz
----- Original Message -----
From: "Boudewijn Ector ICT" <administratie(a)boduewijnector.nl>
To: "users" <users(a)ovirt.org>
Sent: Wednesday, April 30, 2014 5:09:39 PM
Subject: [ovirt-users] "Could not connect host to Data Center" after rebooting,
how to resolve?
Hi list,
I had to do some fsck-related things last week on my ovirt box (centos,
single node and NFS on localhost).
Afterwards ovirt refused to start VMs according to the webinterface
because it can't connect host to Data Center.
On my OS it works fine (I just replaced the IP by 'IP'):
[root@server ovirt-engine]# df
Filesystem 1K-blocks Used Available Use% Mounted on
/dev/mapper/vg_leiden-lv_root
51606140 6872592 42112108 15% /
tmpfs 3978120 0 3978120 0% /dev/shm
/dev/sdb1 495844 99542 370702 22% /boot
/dev/mapper/vg_server-lv_home
62990260 2584272 57206196 5% /home
/dev/sda1 5814366992 4629615452 1184751540 80% /raid
IP:/raid/ovirt/data
5814367232 4629615616 1184751616 80%
/rhev/data-center/mnt/IP:_raid_ovirt_data
IP:/raid/ovirt/iso
5814367232 4629615616 1184751616 80%
/rhev/data-center/mnt/IP:_raid_ovirt_iso
in my event log in the webinterface I found correlation ID 7a735111 .
So grepping my logs for that one:
engine.log:2014-04-30 15:59:22,851 INFO
[org.ovirt.engine.core.bll.storage.ActivateStorageDomainCommand]
(ajp--127.0.0.1-8702-8) [7a735111] Lock Acquired to object EngineLock
[exclusiveLocks= key: 6bee0e2d-961c-453d-a266-e4623f91e162 value: STORAGE
engine.log:2014-04-30 15:59:22,888 INFO
[org.ovirt.engine.core.bll.storage.ActivateStorageDomainCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] Running command:
ActivateStorageDomainCommand internal: false. Entities affected : ID:
6bee0e2d-961c-453d-a266-e4623f91e162 Type: Storage
engine.log:2014-04-30 15:59:22,894 INFO
[org.ovirt.engine.core.bll.storage.ActivateStorageDomainCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] Lock freed to object
EngineLock [exclusiveLocks= key: 6bee0e2d-961c-453d-a266-e4623f91e162
value: STORAGE
engine.log:2014-04-30 15:59:22,895 INFO
[org.ovirt.engine.core.bll.storage.ActivateStorageDomainCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] ActivateStorage Domain.
Before Connect all hosts to pool. Time:4/30/14 3:59 PM
engine.log:2014-04-30 15:59:22,945 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.ActivateStorageDomainVDSCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] START,
ActivateStorageDomainVDSCommand( storagePoolId =
00000002-0002-0002-0002-0000000000ec, ignoreFailoverLimit = false,
storageDomainId = 6bee0e2d-961c-453d-a266-e4623f91e162), log id: 5fecb439
engine.log:2014-04-30 15:59:23,011 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] hostFromVds::selectedVds
- server, spmStatus Unknown_Pool, storage pool Default
engine.log:2014-04-30 15:59:23,015 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] START,
ConnectStoragePoolVDSCommand(HostName = server, HostId =
ff23de79-f17c-439d-939e-d8f3d9672367, storagePoolId =
00000002-0002-0002-0002-0000000000ec, vds_spm_id = 1, masterDomainId =
6bee0e2d-961c-453d-a266-e4623f91e162, masterVersion = 1), log id: 15866a95
engine.log:2014-04-30 15:59:23,151 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] FINISH,
ConnectStoragePoolVDSCommand, log id: 15866a95
engine.log:2014-04-30 15:59:23,152 ERROR
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111]
IrsBroker::Failed::ActivateStorageDomainVDS due to:
IRSNonOperationalException: IRSGenericException: IRSErrorException:
IRSNonOperationalException: Could not connect host to Data
Center(Storage issue)
engine.log:2014-04-30 15:59:23,156 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.ActivateStorageDomainVDSCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] FINISH,
ActivateStorageDomainVDSCommand, log id: 5fecb439
engine.log:2014-04-30 15:59:23,157 ERROR
[org.ovirt.engine.core.bll.storage.ActivateStorageDomainCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] Command
org.ovirt.engine.core.bll.storage.ActivateStorageDomainCommand throw Vdc
Bll exception. With error message VdcBLLException:
org.ovirt.engine.core.vdsbroker.irsbroker.IRSNonOperationalException:
IRSGenericException: IRSErrorException: IRSNonOperationalException:
Could not connect host to Data Center(Storage issue) (Failed with error
ENGINE and code 5001)
engine.log:2014-04-30 15:59:23,162 INFO
[org.ovirt.engine.core.bll.storage.ActivateStorageDomainCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111] Command
[id=c2d8b433-f203-4d9e-b241-222eebf3dbae]: Compensating
CHANGED_STATUS_ONLY of
org.ovirt.engine.core.common.businessentities.StoragePoolIsoMap;
snapshot: EntityStatusSnapshot [id=storagePoolId =
00000002-0002-0002-0002-0000000000ec, storageId =
6bee0e2d-961c-453d-a266-e4623f91e162, status=InActive].
engine.log:2014-04-30 15:59:23,170 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(org.ovirt.thread.pool-6-thread-49) [7a735111] Correlation ID: 7a735111,
Job ID: 75dcda45-e0a3-46e3-b79f-8df9f0ed9d85, Call Stack: null, Custom
Event ID: -1, Message: Failed to activate Storage Domain data (Data
Center Default) by admin
I guess the most relevant error is:
engine.log:2014-04-30 15:59:23,152 ERROR
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
(org.ovirt.thread.pool-6-thread-49) [7a735111]
IrsBroker::Failed::ActivateStorageDomainVDS due to:
IRSNonOperationalException: IRSGenericException: IRSErrorException:
IRSNonOperationalException: Could not connect host to Data
Center(Storage issue)
Okay so it can't connect to the data center. Well the NFS storage is
mounted and looks fine.
The directory is indeed looking fine:
[root@leiden data]# ls -al
total 12
drwxr-xr-x. 3 vdsm kvm 4096 Mar 30 03:27 .
drwxr-xr-x. 4 vdsm kvm 4096 Mar 30 03:26 ..
drwxr-xr-x. 5 vdsm kvm 4096 Mar 30 03:27
6bee0e2d-961c-453d-a266-e4623f91e162
-rwxr-xr-x. 1 vdsm kvm 0 Mar 30 03:27 __DIRECT_IO_TEST__
(and in the uuid there are indeed my VMs).
How should I solve this? To me everything looks just fine.
Cheers
Boudewijn Ector
_______________________________________________
Users mailing list
Users(a)ovirt.org
http://lists.ovirt.org/mailman/listinfo/users
1:48 p.m.
New subject: "Could not connect host to Data Center" after rebooting, how to resolve?
Gadi Ickowicz schreef op 1-5-2014 7:54:
Hi,
Could you please attach the vdsm logs for the host for the time around the logs you
pasted from the engine.log?
Thanks,
Gadi Ickowicz
Sure I wasn't even aware of the /var/log/vdsm directory...
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,043::BindingXMLRPC::251::vds::(wrapper) client [192.168.1.44] flowID [61130377]
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,044::task::595::TaskManager.Task::(_updateState)
Task=`217a7d59-fe83-4be5-b7e5-ce19c17a8d82`::moving from state init -> state preparing
vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:00,044::logUtils::44::dispatcher::(wrapper)
Run and protect: connectStorageServer(domType=1,
spUUID='00000000-0000-0000-0000-000000000000', conList=[{'connection':
'192.168.1.44:/raid/ovirt/data', 'iqn': '', 'portal':
'', 'user': '', 'password': '******',
'id': '3021c4ab-5cb8-455b-be5f-2c79b0e3b23b', 'port':
''}], options=None)
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,048::hsm::2317::Storage.HSM::(__prefetchDomains) nfs local path:
/rhev/data-center/mnt/192.168.1.44:_raid_ovirt_data
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,049::hsm::2341::Storage.HSM::(__prefetchDomains) Found SD uuids:
('6bee0e2d-961c-453d-a266-e4623f91e162',)
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,050::hsm::2397::Storage.HSM::(connectStorageServer) knownSDs:
{6bee0e2d-961c-453d-a266-e4623f91e162: storage.nfsSD.findDomain,
5e8c1e89-f2b8-492c-adb8-e9a9e15a79ee: storage.nfsSD.findDomain}
vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:00,050::logUtils::47::dispatcher::(wrapper)
Run and protect: connectStorageServer, Return response: {'statuslist':
[{'status': 0, 'id': '3021c4ab-5cb8-455b-be5f-2c79b0e3b23b'}]}
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,050::task::1185::TaskManager.Task::(prepare)
Task=`217a7d59-fe83-4be5-b7e5-ce19c17a8d82`::finished: {'statuslist':
[{'status': 0, 'id': '3021c4ab-5cb8-455b-be5f-2c79b0e3b23b'}]}
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,050::task::595::TaskManager.Task::(_updateState)
Task=`217a7d59-fe83-4be5-b7e5-ce19c17a8d82`::moving from state preparing -> state
finished
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,050::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,051::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,051::task::990::TaskManager.Task::(_decref)
Task=`217a7d59-fe83-4be5-b7e5-ce19c17a8d82`::ref 0 aborting False
vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,098::BindingXMLRPC::251::vds::(wrapper)
client [192.168.1.44] flowID [2e8f350]
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,098::task::595::TaskManager.Task::(_updateState)
Task=`dc6f1b1a-1162-4a3d-865d-d9ad9c3603f8`::moving from state init -> state preparing
vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:00,099::logUtils::44::dispatcher::(wrapper)
Run and protect: connectStorageServer(domType=1,
spUUID='00000000-0000-0000-0000-000000000000', conList=[{'connection':
'192.168.1.44:/raid/ovirt/iso', 'iqn': '', 'portal':
'', 'user': '', 'password': '******',
'id': '87de82d7-bc85-41ab-9ca7-3b39a75be919', 'port':
''}], options=None)
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,104::hsm::2317::Storage.HSM::(__prefetchDomains) nfs local path:
/rhev/data-center/mnt/192.168.1.44:_raid_ovirt_iso
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,105::hsm::2341::Storage.HSM::(__prefetchDomains) Found SD uuids:
('5e8c1e89-f2b8-492c-adb8-e9a9e15a79ee',)
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,105::hsm::2397::Storage.HSM::(connectStorageServer) knownSDs:
{6bee0e2d-961c-453d-a266-e4623f91e162: storage.nfsSD.findDomain,
5e8c1e89-f2b8-492c-adb8-e9a9e15a79ee: storage.nfsSD.findDomain}
vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:00,105::logUtils::47::dispatcher::(wrapper)
Run and protect: connectStorageServer, Return response: {'statuslist':
[{'status': 0, 'id': '87de82d7-bc85-41ab-9ca7-3b39a75be919'}]}
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,106::task::1185::TaskManager.Task::(prepare)
Task=`dc6f1b1a-1162-4a3d-865d-d9ad9c3603f8`::finished: {'statuslist':
[{'status': 0, 'id': '87de82d7-bc85-41ab-9ca7-3b39a75be919'}]}
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,106::task::595::TaskManager.Task::(_updateState)
Task=`dc6f1b1a-1162-4a3d-865d-d9ad9c3603f8`::moving from state preparing -> state
finished
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,106::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,106::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,107::task::990::TaskManager.Task::(_decref)
Task=`dc6f1b1a-1162-4a3d-865d-d9ad9c3603f8`::ref 0 aborting False
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:05,841::task::595::TaskManager.Task::(_updateState)
Task=`885311ca-275f-4bdc-9cab-88e91a8ac7c2`::moving from state init -> state preparing
vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:05,841::logUtils::44::dispatcher::(wrapper)
Run and protect: repoStats(options=None)
vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:05,842::logUtils::47::dispatcher::(wrapper)
Run and protect: repoStats, Return response: {}
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:05,842::task::1185::TaskManager.Task::(prepare)
Task=`885311ca-275f-4bdc-9cab-88e91a8ac7c2`::finished: {}
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:05,842::task::595::TaskManager.Task::(_updateState)
Task=`885311ca-275f-4bdc-9cab-88e91a8ac7c2`::moving from state preparing -> state
finished
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:05,842::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:05,842::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:05,843::task::990::TaskManager.Task::(_decref)
Task=`885311ca-275f-4bdc-9cab-88e91a8ac7c2`::ref 0 aborting False
vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,149::BindingXMLRPC::251::vds::(wrapper)
client [192.168.1.44]
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,150::task::595::TaskManager.Task::(_updateState)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::moving from state init -> state preparing
vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:07,150::logUtils::44::dispatcher::(wrapper)
Run and protect: getSpmStatus(spUUID='00000002-0002-0002-0002-0000000000ec',
options=None)
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,150::task::866::TaskManager.Task::(_setError)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Unexpected error
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,158::task::885::TaskManager.Task::(_run)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Task._run:
e4c461f3-6608-43a1-9a48-5a771ac7989c ('00000002-0002-0002-0002-0000000000ec',) {}
failed - stopping task
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,158::task::1211::TaskManager.Task::(stop)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::stopping in state preparing (force False)
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,159::task::990::TaskManager.Task::(_decref)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::ref 1 aborting True
vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,159::task::1168::TaskManager.Task::(prepare)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::aborting: Task is aborted: 'Unknown pool
id, pool not connected' - code 309
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,159::task::1173::TaskManager.Task::(prepare)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Prepare: aborted: Unknown pool id, pool not
connected
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,159::task::990::TaskManager.Task::(_decref)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::ref 0 aborting True
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,159::task::925::TaskManager.Task::(_doAbort)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Task._doAbort: force False
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,160::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,160::task::595::TaskManager.Task::(_updateState)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::moving from state preparing -> state
aborting
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,160::task::550::TaskManager.Task::(__state_aborting)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::_aborting: recover policy none
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,160::task::595::TaskManager.Task::(_updateState)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::moving from state aborting -> state
failed
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,160::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,160::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,161::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,177::BindingXMLRPC::251::vds::(wrapper)
client [192.168.1.44]
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,177::task::595::TaskManager.Task::(_updateState)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::moving from state init -> state preparing
vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:07,177::logUtils::44::dispatcher::(wrapper)
Run and protect: getAllTasksStatuses(spUUID=None, options=None)
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,178::task::866::TaskManager.Task::(_setError)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Unexpected error
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,178::task::885::TaskManager.Task::(_run)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Task._run:
ec07873a-5498-42ff-9403-3ad83f4b08c0 () {} failed - stopping task
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,178::task::1211::TaskManager.Task::(stop)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::stopping in state preparing (force False)
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,178::task::990::TaskManager.Task::(_decref)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::ref 1 aborting True
vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,178::task::1168::TaskManager.Task::(prepare)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::aborting: Task is aborted: 'Not SPM'
- code 654
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,179::task::1173::TaskManager.Task::(prepare)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Prepare: aborted: Not SPM
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,179::task::990::TaskManager.Task::(_decref)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::ref 0 aborting True
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,179::task::925::TaskManager.Task::(_doAbort)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Task._doAbort: force False
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,179::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,179::task::595::TaskManager.Task::(_updateState)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::moving from state preparing -> state
aborting
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,180::task::550::TaskManager.Task::(__state_aborting)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::_aborting: recover policy none
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,180::task::595::TaskManager.Task::(_updateState)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::moving from state aborting -> state
failed
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,180::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,180::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,180::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': 'Not SPM: ()', 'code': 654}}
vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,244::BindingXMLRPC::251::vds::(wrapper)
client [192.168.1.44]
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,244::task::595::TaskManager.Task::(_updateState)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::moving from state init -> state preparing
vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:07,245::logUtils::44::dispatcher::(wrapper)
Run and protect: getSpmStatus(spUUID='00000002-0002-0002-0002-0000000000ec',
options=None)
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,245::task::866::TaskManager.Task::(_setError)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::Unexpected error
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,245::task::885::TaskManager.Task::(_run)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::Task._run:
e4168665-b47d-45f9-8901-727761acbefb ('00000002-0002-0002-0002-0000000000ec',) {}
failed - stopping task
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,246::task::1211::TaskManager.Task::(stop)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::stopping in state preparing (force False)
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,246::task::990::TaskManager.Task::(_decref)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::ref 1 aborting True
vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,246::task::1168::TaskManager.Task::(prepare)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::aborting: Task is aborted: 'Unknown pool
id, pool not connected' - code 309
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,246::task::1173::TaskManager.Task::(prepare)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::Prepare: aborted: Unknown pool id, pool not
connected
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,246::task::990::TaskManager.Task::(_decref)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::ref 0 aborting True
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,246::task::925::TaskManager.Task::(_doAbort)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::Task._doAbort: force False
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,247::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,247::task::595::TaskManager.Task::(_updateState)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::moving from state preparing -> state
aborting
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,247::task::550::TaskManager.Task::(__state_aborting)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::_aborting: recover policy none
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,247::task::595::TaskManager.Task::(_updateState)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::moving from state aborting -> state
failed
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,247::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,247::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,248::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,311::BindingXMLRPC::251::vds::(wrapper)
client [192.168.1.44]
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,312::task::595::TaskManager.Task::(_updateState)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::moving from state init -> state preparing
vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:07,312::logUtils::44::dispatcher::(wrapper)
Run and protect: connectStoragePool(spUUID='00000002-0002-0002-0002-0000000000ec',
hostID=1, msdUUID='6bee0e2d-961c-453d-a266-e4623f91e162', masterVersion=1,
domainsMap=None, options=None)
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,313::resourceManager::198::ResourceManager.Request::(__init__)
ResName=`Storage.HsmDomainMonitorLock`ReqID=`bc44804a-eafd-4c6d-9362-4d1b58dbc332`::Request
was made in '/usr/share/vdsm/storage/hsm.py' line '1007' at
'connectStoragePool'
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,313::resourceManager::542::ResourceManager::(registerResource) Trying to register
resource 'Storage.HsmDomainMonitorLock' for lock type 'exclusive'
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,313::resourceManager::601::ResourceManager::(registerResource) Resource
'Storage.HsmDomainMonitorLock' is free. Now locking as 'exclusive' (1
active user)
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,313::resourceManager::238::ResourceManager.Request::(grant)
ResName=`Storage.HsmDomainMonitorLock`ReqID=`bc44804a-eafd-4c6d-9362-4d1b58dbc332`::Granted
request
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,314::resourceManager::198::ResourceManager.Request::(__init__)
ResName=`Storage.00000002-0002-0002-0002-0000000000ec`ReqID=`92d7be18-2aaf-402d-a185-c36818ee5aa4`::Request
was made in '/usr/share/vdsm/storage/hsm.py' line '1055' at
'_connectStoragePool'
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,314::resourceManager::542::ResourceManager::(registerResource) Trying to register
resource 'Storage.00000002-0002-0002-0002-0000000000ec' for lock type
'exclusive'
pe 'exclusive'
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,314::resourceManager::601::ResourceManager::(registerResource) Resource
'Storage.00000002-0002-0002-0002-0000000000ec' is free. Now locking as
'exclusive' (1 active user)
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,315::resourceManager::238::ResourceManager.Request::(grant)
ResName=`Storage.00000002-0002-0002-0002-0000000000ec`ReqID=`92d7be18-2aaf-402d-a185-c36818ee5aa4`::Granted
request
vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,316::sp::133::Storage.StoragePool::(setBackend) updating pool
00000002-0002-0002-0002-0000000000ec backend from type NoneType instance 0x3cd1372210 to
type StoragePoolDiskBackend instance 0x7f84e8062fc8
vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,316::sp::618::Storage.StoragePool::(connect) Connect host #1 to the storage pool
00000002-0002-0002-0002-0000000000ec with master domain:
6bee0e2d-961c-453d-a266-e4623f91e162 (ver = 1)
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,317::lvm::496::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate
operation' got the operation mutex
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,317::lvm::498::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate
operation' released the operation mutex
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,317::lvm::507::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate
operation' got the operation mutex
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,317::lvm::509::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate
operation' released the operation mutex
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,318::lvm::527::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate
operation' got the operation mutex
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,318::lvm::529::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate
operation' released the operation mutex
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,318::misc::762::SamplingMethod::(__call__) Trying to enter sampling method
(storage.sdc.refreshStorage)
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,318::misc::764::SamplingMethod::(__call__) Got in to sampling method
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,318::misc::762::SamplingMethod::(__call__) Trying to enter sampling method
(storage.iscsi.rescan)
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,318::misc::764::SamplingMethod::(__call__) Got in to sampling method
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,319::iscsi::393::Storage.ISCSI::(rescan) Performing SCSI scan, this will take up
to 30 seconds
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,319::iscsiadm::92::Storage.Misc.excCmd::(_runCmd) '/usr/bin/sudo -n
/sbin/iscsiadm -m session -R' (cwd None)
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,343::misc::772::SamplingMethod::(__call__) Returning last result
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,343::multipath::110::Storage.Misc.excCmd::(rescan) '/usr/bin/sudo -n
/sbin/multipath -r' (cwd None)
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,364::multipath::110::Storage.Misc.excCmd::(rescan) SUCCESS: <err> =
''; <rc> = 0
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,365::lvm::496::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate
operation' got the operation mutex
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,365::lvm::498::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate
operation' released the operation mutex
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,366::lvm::507::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate
operation' got the operation mutex
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,366::lvm::509::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate
operation' released the operation mutex
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,366::lvm::527::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate
operation' got the operation mutex
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,367::lvm::529::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate
operation' released the operation mutex
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,367::misc::772::SamplingMethod::(__call__) Returning last result
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,383::fileSD::140::Storage.StorageDomain::(__init__) Reading domain in path
/rhev/data-center/mnt/192.168.1.44:_raid_ovirt_data/6bee0e2d-961c-453d-a266-e4623f91e162
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,384::persistentDict::192::Storage.PersistentDict::(__init__) Created a persistent
dict with FileMetadataRW backend
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,392::persistentDict::234::Storage.PersistentDict::(refresh) read lines
(FileMetadataRW)=[]
vdsm.log.11:Thread-23::WARNING::2014-04-30
15:50:07,392::persistentDict::256::Storage.PersistentDict::(refresh) data has no embedded
checksum - trust it as it is
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,393::resourceManager::616::ResourceManager::(releaseResource) Trying to release
resource 'Storage.00000002-0002-0002-0002-0000000000ec'
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,393::resourceManager::635::ResourceManager::(releaseResource) Released resource
'Storage.00000002-0002-0002-0002-0000000000ec' (0 active users)
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,393::resourceManager::641::ResourceManager::(releaseResource) Resource
'Storage.00000002-0002-0002-0002-0000000000ec' is free, finding out if anyone is
waiting for it.
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,393::resourceManager::649::ResourceManager::(releaseResource) No one is waiting
for resource 'Storage.00000002-0002-0002-0002-0000000000ec', Clearing records.
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,394::resourceManager::616::ResourceManager::(releaseResource) Trying to release
resource 'Storage.HsmDomainMonitorLock'
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,394::resourceManager::635::ResourceManager::(releaseResource) Released resource
'Storage.HsmDomainMonitorLock' (0 active users)
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,394::resourceManager::641::ResourceManager::(releaseResource) Resource
'Storage.HsmDomainMonitorLock' is free, finding out if anyone is waiting for it.
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,395::resourceManager::649::ResourceManager::(releaseResource) No one is waiting
for resource 'Storage.HsmDomainMonitorLock', Clearing records.
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,395::task::866::TaskManager.Task::(_setError)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::Unexpected error
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,396::task::885::TaskManager.Task::(_run)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::Task._run:
b9440814-a49e-446f-bfee-05f3bb3f73fd ('00000002-0002-0002-0002-0000000000ec', 1,
'6bee0e2d-961c-453d-a266-e4623f91e162', 1, None) {} failed - stopping task
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,396::task::1211::TaskManager.Task::(stop)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::stopping in state preparing (force False)
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,396::task::990::TaskManager.Task::(_decref)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::ref 1 aborting True
vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,397::task::1168::TaskManager.Task::(prepare)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::aborting: Task is aborted:
u"'VERSION'" - code 100
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,397::task::1173::TaskManager.Task::(prepare)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::Prepare: aborted: 'VERSION'
vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,397::task::990::TaskManager.Task::(_decref)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::ref 0 aborting True
When looking for messages with ERROR or WARNING tags:
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,150::task::866::TaskManager.Task::(_setError)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Unexpected error
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,161::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,178::task::866::TaskManager.Task::(_setError)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Unexpected error
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,180::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': 'Not SPM: ()', 'code': 654}}
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,245::task::866::TaskManager.Task::(_setError)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::Unexpected error
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,248::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
vdsm.log.11:Thread-23::WARNING::2014-04-30
15:50:07,392::persistentDict::256::Storage.PersistentDict::(refresh) data has no embedded
checksum - trust it as it is
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,395::task::866::TaskManager.Task::(_setError)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::Unexpected error
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,399::dispatcher::68::Storage.Dispatcher.Protect::(run) 'VERSION'
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,462::task::866::TaskManager.Task::(_setError)
Task=`c107a3de-819b-44c5-8739-f31ea6cc3b91`::Unexpected error
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,465::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,493::task::866::TaskManager.Task::(_setError)
Task=`df7f16b1-72fe-43e9-ab76-7b59a694819e`::Unexpected error
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,496::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': 'Not SPM: ()', 'code': 654}}
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,558::task::866::TaskManager.Task::(_setError)
Task=`68c69145-33b5-4fcb-8c91-47b27edf2d98`::Unexpected error
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,561::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
vdsm.log.11:Thread-23::WARNING::2014-04-30
15:50:17,694::persistentDict::256::Storage.PersistentDict::(refresh) data has no embedded
checksum - trust it as it is
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,697::task::866::TaskManager.Task::(_setError)
Task=`f807fd52-5495-4633-8615-b0923ff16e1d`::Unexpected error
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,701::dispatcher::68::Storage.Dispatcher.Protect::(run) 'VERSION'
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:27,765::task::866::TaskManager.Task::(_setError)
Task=`5a0268e4-58e4-4e5f-a87a-89da345d373e`::Unexpected error
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:27,768::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:27,786::task::866::TaskManager.Task::(_setError)
Task=`7e2d100d-3670-4b91-b861-9fbd43c5b110`::Unexpected error
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:27,789::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': 'Not SPM: ()', 'code': 654}}
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:27,860::task::866::TaskManager.Task::(_setError)
Task=`833a9952-107a-437a-bc93-99849e0e0612`::Unexpected error
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:27,865::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
vdsm.log.11:Thread-23::WARNING::2014-04-30
15:50:28,010::persistentDict::256::Storage.PersistentDict::(refresh) data has no embedded
checksum - trust it as it is
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:28,013::task::866::TaskManager.Task::(_setError)
Task=`e999e46e-9a5f-43ba-881d-145c38fcb18f`::Unexpected error
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:28,017::dispatcher::68::Storage.Dispatcher.Protect::(run) 'VERSION'
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:38,078::task::866::TaskManager.Task::(_setError)
Task=`7d632291-beb9-4bec-9d14-ce9b7d240e49`::Unexpected error
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:38,082::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:38,097::task::866::TaskManager.Task::(_setError)
Task=`1f7a2469-c5f5-460f-a09e-3ff7f666dfe1`::Unexpected error
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:38,101::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': 'Not SPM: ()', 'code': 654}}
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:38,163::task::866::TaskManager.Task::(_setError)
Task=`a793071a-13e2-4c66-8c63-34501c7becec`::Unexpected error
vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:38,166::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
Thank you very much already.
Boudewijn Ector
11:44 p.m.
New subject: "Could not connect host to Data Center" after rebooting, how to resolve?
On 01-05-14 12:48, Boudewijn Ector wrote:
Gadi Ickowicz schreef op 1-5-2014 7:54:
> Hi,
>
> Could you please attach the vdsm logs for the host for the time around the logs you
pasted from the engine.log?
>
> Thanks,
> Gadi Ickowicz
>
Sure I wasn't even aware of the /var/log/vdsm directory...
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,043::BindingXMLRPC::251::vds::(wrapper) client [192.168.1.44] flowID [61130377]
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,044::task::595::TaskManager.Task::(_updateState)
Task=`217a7d59-fe83-4be5-b7e5-ce19c17a8d82`::moving from state init -> state preparing
> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:00,044::logUtils::44::dispatcher::(wrapper) Run and protect:
connectStorageServer(domType=1, spUUID='00000000-0000-0000-0000-000000000000',
conList=[{'connection': '192.168.1.44:/raid/ovirt/data', 'iqn':
'', 'portal': '', 'user': '', 'password':
'******', 'id': '3021c4ab-5cb8-455b-be5f-2c79b0e3b23b',
'port': ''}], options=None)
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,048::hsm::2317::Storage.HSM::(__prefetchDomains) nfs local path:
/rhev/data-center/mnt/192.168.1.44:_raid_ovirt_data
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,049::hsm::2341::Storage.HSM::(__prefetchDomains) Found SD uuids:
('6bee0e2d-961c-453d-a266-e4623f91e162',)
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,050::hsm::2397::Storage.HSM::(connectStorageServer) knownSDs:
{6bee0e2d-961c-453d-a266-e4623f91e162: storage.nfsSD.findDomain,
5e8c1e89-f2b8-492c-adb8-e9a9e15a79ee: storage.nfsSD.findDomain}
> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:00,050::logUtils::47::dispatcher::(wrapper) Run and protect: connectStorageServer,
Return response: {'statuslist': [{'status': 0, 'id':
'3021c4ab-5cb8-455b-be5f-2c79b0e3b23b'}]}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,050::task::1185::TaskManager.Task::(prepare)
Task=`217a7d59-fe83-4be5-b7e5-ce19c17a8d82`::finished: {'statuslist':
[{'status': 0, 'id': '3021c4ab-5cb8-455b-be5f-2c79b0e3b23b'}]}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,050::task::595::TaskManager.Task::(_updateState)
Task=`217a7d59-fe83-4be5-b7e5-ce19c17a8d82`::moving from state preparing -> state
finished
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,050::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,051::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,051::task::990::TaskManager.Task::(_decref)
Task=`217a7d59-fe83-4be5-b7e5-ce19c17a8d82`::ref 0 aborting False
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,098::BindingXMLRPC::251::vds::(wrapper) client [192.168.1.44] flowID [2e8f350]
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,098::task::595::TaskManager.Task::(_updateState)
Task=`dc6f1b1a-1162-4a3d-865d-d9ad9c3603f8`::moving from state init -> state preparing
> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:00,099::logUtils::44::dispatcher::(wrapper) Run and protect:
connectStorageServer(domType=1, spUUID='00000000-0000-0000-0000-000000000000',
conList=[{'connection': '192.168.1.44:/raid/ovirt/iso', 'iqn':
'', 'portal': '', 'user': '', 'password':
'******', 'id': '87de82d7-bc85-41ab-9ca7-3b39a75be919',
'port': ''}], options=None)
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,104::hsm::2317::Storage.HSM::(__prefetchDomains) nfs local path:
/rhev/data-center/mnt/192.168.1.44:_raid_ovirt_iso
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,105::hsm::2341::Storage.HSM::(__prefetchDomains) Found SD uuids:
('5e8c1e89-f2b8-492c-adb8-e9a9e15a79ee',)
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,105::hsm::2397::Storage.HSM::(connectStorageServer) knownSDs:
{6bee0e2d-961c-453d-a266-e4623f91e162: storage.nfsSD.findDomain,
5e8c1e89-f2b8-492c-adb8-e9a9e15a79ee: storage.nfsSD.findDomain}
> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:00,105::logUtils::47::dispatcher::(wrapper) Run and protect: connectStorageServer,
Return response: {'statuslist': [{'status': 0, 'id':
'87de82d7-bc85-41ab-9ca7-3b39a75be919'}]}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,106::task::1185::TaskManager.Task::(prepare)
Task=`dc6f1b1a-1162-4a3d-865d-d9ad9c3603f8`::finished: {'statuslist':
[{'status': 0, 'id': '87de82d7-bc85-41ab-9ca7-3b39a75be919'}]}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,106::task::595::TaskManager.Task::(_updateState)
Task=`dc6f1b1a-1162-4a3d-865d-d9ad9c3603f8`::moving from state preparing -> state
finished
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,106::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,106::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,107::task::990::TaskManager.Task::(_decref)
Task=`dc6f1b1a-1162-4a3d-865d-d9ad9c3603f8`::ref 0 aborting False
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:05,841::task::595::TaskManager.Task::(_updateState)
Task=`885311ca-275f-4bdc-9cab-88e91a8ac7c2`::moving from state init -> state preparing
> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:05,841::logUtils::44::dispatcher::(wrapper) Run and protect:
repoStats(options=None)
> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:05,842::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return
response: {}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:05,842::task::1185::TaskManager.Task::(prepare)
Task=`885311ca-275f-4bdc-9cab-88e91a8ac7c2`::finished: {}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:05,842::task::595::TaskManager.Task::(_updateState)
Task=`885311ca-275f-4bdc-9cab-88e91a8ac7c2`::moving from state preparing -> state
finished
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:05,842::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:05,842::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:05,843::task::990::TaskManager.Task::(_decref)
Task=`885311ca-275f-4bdc-9cab-88e91a8ac7c2`::ref 0 aborting False
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,149::BindingXMLRPC::251::vds::(wrapper) client [192.168.1.44]
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,150::task::595::TaskManager.Task::(_updateState)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::moving from state init -> state preparing
> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,150::logUtils::44::dispatcher::(wrapper) Run and protect:
getSpmStatus(spUUID='00000002-0002-0002-0002-0000000000ec', options=None)
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,150::task::866::TaskManager.Task::(_setError)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Unexpected error
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,158::task::885::TaskManager.Task::(_run)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Task._run:
e4c461f3-6608-43a1-9a48-5a771ac7989c ('00000002-0002-0002-0002-0000000000ec',) {}
failed - stopping task
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,158::task::1211::TaskManager.Task::(stop)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::stopping in state preparing (force False)
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,159::task::990::TaskManager.Task::(_decref)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::ref 1 aborting True
> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,159::task::1168::TaskManager.Task::(prepare)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::aborting: Task is aborted: 'Unknown pool
id, pool not connected' - code 309
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,159::task::1173::TaskManager.Task::(prepare)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Prepare: aborted: Unknown pool id, pool not
connected
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,159::task::990::TaskManager.Task::(_decref)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::ref 0 aborting True
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,159::task::925::TaskManager.Task::(_doAbort)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Task._doAbort: force False
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,160::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,160::task::595::TaskManager.Task::(_updateState)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::moving from state preparing -> state
aborting
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,160::task::550::TaskManager.Task::(__state_aborting)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::_aborting: recover policy none
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,160::task::595::TaskManager.Task::(_updateState)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::moving from state aborting -> state
failed
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,160::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,160::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,161::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,177::BindingXMLRPC::251::vds::(wrapper) client [192.168.1.44]
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,177::task::595::TaskManager.Task::(_updateState)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::moving from state init -> state preparing
> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,177::logUtils::44::dispatcher::(wrapper) Run and protect:
getAllTasksStatuses(spUUID=None, options=None)
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,178::task::866::TaskManager.Task::(_setError)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Unexpected error
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,178::task::885::TaskManager.Task::(_run)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Task._run:
ec07873a-5498-42ff-9403-3ad83f4b08c0 () {} failed - stopping task
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,178::task::1211::TaskManager.Task::(stop)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::stopping in state preparing (force False)
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,178::task::990::TaskManager.Task::(_decref)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::ref 1 aborting True
> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,178::task::1168::TaskManager.Task::(prepare)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::aborting: Task is aborted: 'Not SPM'
- code 654
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,179::task::1173::TaskManager.Task::(prepare)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Prepare: aborted: Not SPM
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,179::task::990::TaskManager.Task::(_decref)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::ref 0 aborting True
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,179::task::925::TaskManager.Task::(_doAbort)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Task._doAbort: force False
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,179::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,179::task::595::TaskManager.Task::(_updateState)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::moving from state preparing -> state
aborting
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,180::task::550::TaskManager.Task::(__state_aborting)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::_aborting: recover policy none
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,180::task::595::TaskManager.Task::(_updateState)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::moving from state aborting -> state
failed
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,180::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,180::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,180::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': 'Not SPM: ()', 'code': 654}}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,244::BindingXMLRPC::251::vds::(wrapper) client [192.168.1.44]
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,244::task::595::TaskManager.Task::(_updateState)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::moving from state init -> state preparing
> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,245::logUtils::44::dispatcher::(wrapper) Run and protect:
getSpmStatus(spUUID='00000002-0002-0002-0002-0000000000ec', options=None)
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,245::task::866::TaskManager.Task::(_setError)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::Unexpected error
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,245::task::885::TaskManager.Task::(_run)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::Task._run:
e4168665-b47d-45f9-8901-727761acbefb ('00000002-0002-0002-0002-0000000000ec',) {}
failed - stopping task
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,246::task::1211::TaskManager.Task::(stop)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::stopping in state preparing (force False)
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,246::task::990::TaskManager.Task::(_decref)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::ref 1 aborting True
> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,246::task::1168::TaskManager.Task::(prepare)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::aborting: Task is aborted: 'Unknown pool
id, pool not connected' - code 309
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,246::task::1173::TaskManager.Task::(prepare)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::Prepare: aborted: Unknown pool id, pool not
connected
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,246::task::990::TaskManager.Task::(_decref)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::ref 0 aborting True
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,246::task::925::TaskManager.Task::(_doAbort)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::Task._doAbort: force False
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,247::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,247::task::595::TaskManager.Task::(_updateState)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::moving from state preparing -> state
aborting
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,247::task::550::TaskManager.Task::(__state_aborting)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::_aborting: recover policy none
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,247::task::595::TaskManager.Task::(_updateState)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::moving from state aborting -> state
failed
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,247::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,247::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,248::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,311::BindingXMLRPC::251::vds::(wrapper) client [192.168.1.44]
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,312::task::595::TaskManager.Task::(_updateState)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::moving from state init -> state preparing
> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,312::logUtils::44::dispatcher::(wrapper) Run and protect:
connectStoragePool(spUUID='00000002-0002-0002-0002-0000000000ec', hostID=1,
msdUUID='6bee0e2d-961c-453d-a266-e4623f91e162', masterVersion=1, domainsMap=None,
options=None)
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,313::resourceManager::198::ResourceManager.Request::(__init__)
ResName=`Storage.HsmDomainMonitorLock`ReqID=`bc44804a-eafd-4c6d-9362-4d1b58dbc332`::Request
was made in '/usr/share/vdsm/storage/hsm.py' line '1007' at
'connectStoragePool'
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,313::resourceManager::542::ResourceManager::(registerResource) Trying to register
resource 'Storage.HsmDomainMonitorLock' for lock type 'exclusive'
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,313::resourceManager::601::ResourceManager::(registerResource) Resource
'Storage.HsmDomainMonitorLock' is free. Now locking as 'exclusive' (1
active user)
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,313::resourceManager::238::ResourceManager.Request::(grant)
ResName=`Storage.HsmDomainMonitorLock`ReqID=`bc44804a-eafd-4c6d-9362-4d1b58dbc332`::Granted
request
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,314::resourceManager::198::ResourceManager.Request::(__init__)
ResName=`Storage.00000002-0002-0002-0002-0000000000ec`ReqID=`92d7be18-2aaf-402d-a185-c36818ee5aa4`::Request
was made in '/usr/share/vdsm/storage/hsm.py' line '1055' at
'_connectStoragePool'
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,314::resourceManager::542::ResourceManager::(registerResource) Trying to register
resource 'Storage.00000002-0002-0002-0002-0000000000ec' for lock type
'exclusive'
> pe 'exclusive'
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,314::resourceManager::601::ResourceManager::(registerResource) Resource
'Storage.00000002-0002-0002-0002-0000000000ec' is free. Now locking as
'exclusive' (1 active user)
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,315::resourceManager::238::ResourceManager.Request::(grant)
ResName=`Storage.00000002-0002-0002-0002-0000000000ec`ReqID=`92d7be18-2aaf-402d-a185-c36818ee5aa4`::Granted
request
> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,316::sp::133::Storage.StoragePool::(setBackend) updating pool
00000002-0002-0002-0002-0000000000ec backend from type NoneType instance 0x3cd1372210 to
type StoragePoolDiskBackend instance 0x7f84e8062fc8
> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,316::sp::618::Storage.StoragePool::(connect) Connect host #1 to the storage pool
00000002-0002-0002-0002-0000000000ec with master domain:
6bee0e2d-961c-453d-a266-e4623f91e162 (ver = 1)
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,317::lvm::496::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate
operation' got the operation mutex
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,317::lvm::498::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate
operation' released the operation mutex
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,317::lvm::507::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate
operation' got the operation mutex
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,317::lvm::509::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate
operation' released the operation mutex
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,318::lvm::527::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate
operation' got the operation mutex
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,318::lvm::529::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate
operation' released the operation mutex
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,318::misc::762::SamplingMethod::(__call__) Trying to enter sampling method
(storage.sdc.refreshStorage)
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,318::misc::764::SamplingMethod::(__call__) Got in to sampling method
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,318::misc::762::SamplingMethod::(__call__) Trying to enter sampling method
(storage.iscsi.rescan)
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,318::misc::764::SamplingMethod::(__call__) Got in to sampling method
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,319::iscsi::393::Storage.ISCSI::(rescan) Performing SCSI scan, this will take up
to 30 seconds
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,319::iscsiadm::92::Storage.Misc.excCmd::(_runCmd) '/usr/bin/sudo -n
/sbin/iscsiadm -m session -R' (cwd None)
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,343::misc::772::SamplingMethod::(__call__) Returning last result
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,343::multipath::110::Storage.Misc.excCmd::(rescan) '/usr/bin/sudo -n
/sbin/multipath -r' (cwd None)
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,364::multipath::110::Storage.Misc.excCmd::(rescan) SUCCESS: <err> =
''; <rc> = 0
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,365::lvm::496::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate
operation' got the operation mutex
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,365::lvm::498::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate
operation' released the operation mutex
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,366::lvm::507::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate
operation' got the operation mutex
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,366::lvm::509::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate
operation' released the operation mutex
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,366::lvm::527::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate
operation' got the operation mutex
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,367::lvm::529::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate
operation' released the operation mutex
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,367::misc::772::SamplingMethod::(__call__) Returning last result
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,383::fileSD::140::Storage.StorageDomain::(__init__) Reading domain in path
/rhev/data-center/mnt/192.168.1.44:_raid_ovirt_data/6bee0e2d-961c-453d-a266-e4623f91e162
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,384::persistentDict::192::Storage.PersistentDict::(__init__) Created a persistent
dict with FileMetadataRW backend
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,392::persistentDict::234::Storage.PersistentDict::(refresh) read lines
(FileMetadataRW)=[]
> vdsm.log.11:Thread-23::WARNING::2014-04-30
15:50:07,392::persistentDict::256::Storage.PersistentDict::(refresh) data has no embedded
checksum - trust it as it is
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,393::resourceManager::616::ResourceManager::(releaseResource) Trying to release
resource 'Storage.00000002-0002-0002-0002-0000000000ec'
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,393::resourceManager::635::ResourceManager::(releaseResource) Released resource
'Storage.00000002-0002-0002-0002-0000000000ec' (0 active users)
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,393::resourceManager::641::ResourceManager::(releaseResource) Resource
'Storage.00000002-0002-0002-0002-0000000000ec' is free, finding out if anyone is
waiting for it.
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,393::resourceManager::649::ResourceManager::(releaseResource) No one is waiting
for resource 'Storage.00000002-0002-0002-0002-0000000000ec', Clearing records.
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,394::resourceManager::616::ResourceManager::(releaseResource) Trying to release
resource 'Storage.HsmDomainMonitorLock'
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,394::resourceManager::635::ResourceManager::(releaseResource) Released resource
'Storage.HsmDomainMonitorLock' (0 active users)
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,394::resourceManager::641::ResourceManager::(releaseResource) Resource
'Storage.HsmDomainMonitorLock' is free, finding out if anyone is waiting for it.
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,395::resourceManager::649::ResourceManager::(releaseResource) No one is waiting
for resource 'Storage.HsmDomainMonitorLock', Clearing records.
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,395::task::866::TaskManager.Task::(_setError)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::Unexpected error
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,396::task::885::TaskManager.Task::(_run)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::Task._run:
b9440814-a49e-446f-bfee-05f3bb3f73fd ('00000002-0002-0002-0002-0000000000ec', 1,
'6bee0e2d-961c-453d-a266-e4623f91e162', 1, None) {} failed - stopping task
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,396::task::1211::TaskManager.Task::(stop)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::stopping in state preparing (force False)
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,396::task::990::TaskManager.Task::(_decref)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::ref 1 aborting True
> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,397::task::1168::TaskManager.Task::(prepare)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::aborting: Task is aborted:
u"'VERSION'" - code 100
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,397::task::1173::TaskManager.Task::(prepare)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::Prepare: aborted: 'VERSION'
> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,397::task::990::TaskManager.Task::(_decref)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::ref 0 aborting True
When looking for messages with ERROR or WARNING tags:
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,150::task::866::TaskManager.Task::(_setError)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Unexpected error
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,161::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,178::task::866::TaskManager.Task::(_setError)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Unexpected error
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,180::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': 'Not SPM: ()', 'code': 654}}
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,245::task::866::TaskManager.Task::(_setError)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::Unexpected error
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,248::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
> vdsm.log.11:Thread-23::WARNING::2014-04-30
15:50:07,392::persistentDict::256::Storage.PersistentDict::(refresh) data has no embedded
checksum - trust it as it is
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,395::task::866::TaskManager.Task::(_setError)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::Unexpected error
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,399::dispatcher::68::Storage.Dispatcher.Protect::(run) 'VERSION'
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,462::task::866::TaskManager.Task::(_setError)
Task=`c107a3de-819b-44c5-8739-f31ea6cc3b91`::Unexpected error
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,465::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,493::task::866::TaskManager.Task::(_setError)
Task=`df7f16b1-72fe-43e9-ab76-7b59a694819e`::Unexpected error
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,496::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': 'Not SPM: ()', 'code': 654}}
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,558::task::866::TaskManager.Task::(_setError)
Task=`68c69145-33b5-4fcb-8c91-47b27edf2d98`::Unexpected error
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,561::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
> vdsm.log.11:Thread-23::WARNING::2014-04-30
15:50:17,694::persistentDict::256::Storage.PersistentDict::(refresh) data has no embedded
checksum - trust it as it is
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,697::task::866::TaskManager.Task::(_setError)
Task=`f807fd52-5495-4633-8615-b0923ff16e1d`::Unexpected error
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,701::dispatcher::68::Storage.Dispatcher.Protect::(run) 'VERSION'
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:27,765::task::866::TaskManager.Task::(_setError)
Task=`5a0268e4-58e4-4e5f-a87a-89da345d373e`::Unexpected error
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:27,768::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:27,786::task::866::TaskManager.Task::(_setError)
Task=`7e2d100d-3670-4b91-b861-9fbd43c5b110`::Unexpected error
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:27,789::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': 'Not SPM: ()', 'code': 654}}
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:27,860::task::866::TaskManager.Task::(_setError)
Task=`833a9952-107a-437a-bc93-99849e0e0612`::Unexpected error
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:27,865::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
> vdsm.log.11:Thread-23::WARNING::2014-04-30
15:50:28,010::persistentDict::256::Storage.PersistentDict::(refresh) data has no embedded
checksum - trust it as it is
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:28,013::task::866::TaskManager.Task::(_setError)
Task=`e999e46e-9a5f-43ba-881d-145c38fcb18f`::Unexpected error
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:28,017::dispatcher::68::Storage.Dispatcher.Protect::(run) 'VERSION'
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:38,078::task::866::TaskManager.Task::(_setError)
Task=`7d632291-beb9-4bec-9d14-ce9b7d240e49`::Unexpected error
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:38,082::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:38,097::task::866::TaskManager.Task::(_setError)
Task=`1f7a2469-c5f5-460f-a09e-3ff7f666dfe1`::Unexpected error
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:38,101::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': 'Not SPM: ()', 'code': 654}}
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:38,163::task::866::TaskManager.Task::(_setError)
Task=`a793071a-13e2-4c66-8c63-34501c7becec`::Unexpected error
> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:38,166::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
>
>
Thank you very much already.
Boudewijn Ector
_______________________________________________
Users mailing list
Users(a)ovirt.org
http://lists.ovirt.org/mailman/listinfo/users
Bump, anyone? I'm quite a bit disappointed about the lack of
debugability of ovirt actually.
Cheers,
Boudewijn
7:54 p.m.
New subject: "Could not connect host to Data Center" after rebooting, how to resolve?
On 05/05/2014 11:44 PM, Boudewijn Ector wrote:
On 01-05-14 12:48, Boudewijn Ector wrote:
> Gadi Ickowicz schreef op 1-5-2014 7:54:
>> Hi,
>>
>> Could you please attach the vdsm logs for the host for the time around the logs
you pasted from the engine.log?
>>
>> Thanks,
>> Gadi Ickowicz
>>
> Sure I wasn't even aware of the /var/log/vdsm directory...
>
>
>
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,043::BindingXMLRPC::251::vds::(wrapper) client [192.168.1.44] flowID [61130377]
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,044::task::595::TaskManager.Task::(_updateState)
Task=`217a7d59-fe83-4be5-b7e5-ce19c17a8d82`::moving from state init -> state preparing
>> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:00,044::logUtils::44::dispatcher::(wrapper) Run and protect:
connectStorageServer(domType=1, spUUID='00000000-0000-0000-0000-000000000000',
conList=[{'connection': '192.168.1.44:/raid/ovirt/data', 'iqn':
'', 'portal': '', 'user': '', 'password':
'******', 'id': '3021c4ab-5cb8-455b-be5f-2c79b0e3b23b',
'port': ''}], options=None)
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,048::hsm::2317::Storage.HSM::(__prefetchDomains) nfs local path:
/rhev/data-center/mnt/192.168.1.44:_raid_ovirt_data
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,049::hsm::2341::Storage.HSM::(__prefetchDomains) Found SD uuids:
('6bee0e2d-961c-453d-a266-e4623f91e162',)
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,050::hsm::2397::Storage.HSM::(connectStorageServer) knownSDs:
{6bee0e2d-961c-453d-a266-e4623f91e162: storage.nfsSD.findDomain,
5e8c1e89-f2b8-492c-adb8-e9a9e15a79ee: storage.nfsSD.findDomain}
>> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:00,050::logUtils::47::dispatcher::(wrapper) Run and protect: connectStorageServer,
Return response: {'statuslist': [{'status': 0, 'id':
'3021c4ab-5cb8-455b-be5f-2c79b0e3b23b'}]}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,050::task::1185::TaskManager.Task::(prepare)
Task=`217a7d59-fe83-4be5-b7e5-ce19c17a8d82`::finished: {'statuslist':
[{'status': 0, 'id': '3021c4ab-5cb8-455b-be5f-2c79b0e3b23b'}]}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,050::task::595::TaskManager.Task::(_updateState)
Task=`217a7d59-fe83-4be5-b7e5-ce19c17a8d82`::moving from state preparing -> state
finished
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,050::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,051::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,051::task::990::TaskManager.Task::(_decref)
Task=`217a7d59-fe83-4be5-b7e5-ce19c17a8d82`::ref 0 aborting False
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,098::BindingXMLRPC::251::vds::(wrapper) client [192.168.1.44] flowID [2e8f350]
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,098::task::595::TaskManager.Task::(_updateState)
Task=`dc6f1b1a-1162-4a3d-865d-d9ad9c3603f8`::moving from state init -> state preparing
>> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:00,099::logUtils::44::dispatcher::(wrapper) Run and protect:
connectStorageServer(domType=1, spUUID='00000000-0000-0000-0000-000000000000',
conList=[{'connection': '192.168.1.44:/raid/ovirt/iso', 'iqn':
'', 'portal': '', 'user': '', 'password':
'******', 'id': '87de82d7-bc85-41ab-9ca7-3b39a75be919',
'port': ''}], options=None)
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,104::hsm::2317::Storage.HSM::(__prefetchDomains) nfs local path:
/rhev/data-center/mnt/192.168.1.44:_raid_ovirt_iso
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,105::hsm::2341::Storage.HSM::(__prefetchDomains) Found SD uuids:
('5e8c1e89-f2b8-492c-adb8-e9a9e15a79ee',)
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,105::hsm::2397::Storage.HSM::(connectStorageServer) knownSDs:
{6bee0e2d-961c-453d-a266-e4623f91e162: storage.nfsSD.findDomain,
5e8c1e89-f2b8-492c-adb8-e9a9e15a79ee: storage.nfsSD.findDomain}
>> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:00,105::logUtils::47::dispatcher::(wrapper) Run and protect: connectStorageServer,
Return response: {'statuslist': [{'status': 0, 'id':
'87de82d7-bc85-41ab-9ca7-3b39a75be919'}]}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,106::task::1185::TaskManager.Task::(prepare)
Task=`dc6f1b1a-1162-4a3d-865d-d9ad9c3603f8`::finished: {'statuslist':
[{'status': 0, 'id': '87de82d7-bc85-41ab-9ca7-3b39a75be919'}]}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,106::task::595::TaskManager.Task::(_updateState)
Task=`dc6f1b1a-1162-4a3d-865d-d9ad9c3603f8`::moving from state preparing -> state
finished
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,106::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,106::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:00,107::task::990::TaskManager.Task::(_decref)
Task=`dc6f1b1a-1162-4a3d-865d-d9ad9c3603f8`::ref 0 aborting False
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:05,841::task::595::TaskManager.Task::(_updateState)
Task=`885311ca-275f-4bdc-9cab-88e91a8ac7c2`::moving from state init -> state preparing
>> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:05,841::logUtils::44::dispatcher::(wrapper) Run and protect:
repoStats(options=None)
>> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:05,842::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return
response: {}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:05,842::task::1185::TaskManager.Task::(prepare)
Task=`885311ca-275f-4bdc-9cab-88e91a8ac7c2`::finished: {}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:05,842::task::595::TaskManager.Task::(_updateState)
Task=`885311ca-275f-4bdc-9cab-88e91a8ac7c2`::moving from state preparing -> state
finished
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:05,842::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:05,842::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:05,843::task::990::TaskManager.Task::(_decref)
Task=`885311ca-275f-4bdc-9cab-88e91a8ac7c2`::ref 0 aborting False
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,149::BindingXMLRPC::251::vds::(wrapper) client [192.168.1.44]
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,150::task::595::TaskManager.Task::(_updateState)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::moving from state init -> state preparing
>> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,150::logUtils::44::dispatcher::(wrapper) Run and protect:
getSpmStatus(spUUID='00000002-0002-0002-0002-0000000000ec', options=None)
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,150::task::866::TaskManager.Task::(_setError)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Unexpected error
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,158::task::885::TaskManager.Task::(_run)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Task._run:
e4c461f3-6608-43a1-9a48-5a771ac7989c ('00000002-0002-0002-0002-0000000000ec',) {}
failed - stopping task
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,158::task::1211::TaskManager.Task::(stop)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::stopping in state preparing (force False)
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,159::task::990::TaskManager.Task::(_decref)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::ref 1 aborting True
>> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,159::task::1168::TaskManager.Task::(prepare)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::aborting: Task is aborted: 'Unknown pool
id, pool not connected' - code 309
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,159::task::1173::TaskManager.Task::(prepare)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Prepare: aborted: Unknown pool id, pool not
connected
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,159::task::990::TaskManager.Task::(_decref)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::ref 0 aborting True
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,159::task::925::TaskManager.Task::(_doAbort)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Task._doAbort: force False
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,160::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,160::task::595::TaskManager.Task::(_updateState)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::moving from state preparing -> state
aborting
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,160::task::550::TaskManager.Task::(__state_aborting)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::_aborting: recover policy none
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,160::task::595::TaskManager.Task::(_updateState)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::moving from state aborting -> state
failed
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,160::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,160::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,161::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,177::BindingXMLRPC::251::vds::(wrapper) client [192.168.1.44]
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,177::task::595::TaskManager.Task::(_updateState)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::moving from state init -> state preparing
>> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,177::logUtils::44::dispatcher::(wrapper) Run and protect:
getAllTasksStatuses(spUUID=None, options=None)
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,178::task::866::TaskManager.Task::(_setError)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Unexpected error
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,178::task::885::TaskManager.Task::(_run)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Task._run:
ec07873a-5498-42ff-9403-3ad83f4b08c0 () {} failed - stopping task
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,178::task::1211::TaskManager.Task::(stop)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::stopping in state preparing (force False)
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,178::task::990::TaskManager.Task::(_decref)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::ref 1 aborting True
>> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,178::task::1168::TaskManager.Task::(prepare)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::aborting: Task is aborted: 'Not SPM'
- code 654
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,179::task::1173::TaskManager.Task::(prepare)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Prepare: aborted: Not SPM
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,179::task::990::TaskManager.Task::(_decref)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::ref 0 aborting True
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,179::task::925::TaskManager.Task::(_doAbort)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Task._doAbort: force False
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,179::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,179::task::595::TaskManager.Task::(_updateState)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::moving from state preparing -> state
aborting
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,180::task::550::TaskManager.Task::(__state_aborting)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::_aborting: recover policy none
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,180::task::595::TaskManager.Task::(_updateState)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::moving from state aborting -> state
failed
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,180::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,180::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,180::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': 'Not SPM: ()', 'code': 654}}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,244::BindingXMLRPC::251::vds::(wrapper) client [192.168.1.44]
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,244::task::595::TaskManager.Task::(_updateState)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::moving from state init -> state preparing
>> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,245::logUtils::44::dispatcher::(wrapper) Run and protect:
getSpmStatus(spUUID='00000002-0002-0002-0002-0000000000ec', options=None)
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,245::task::866::TaskManager.Task::(_setError)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::Unexpected error
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,245::task::885::TaskManager.Task::(_run)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::Task._run:
e4168665-b47d-45f9-8901-727761acbefb ('00000002-0002-0002-0002-0000000000ec',) {}
failed - stopping task
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,246::task::1211::TaskManager.Task::(stop)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::stopping in state preparing (force False)
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,246::task::990::TaskManager.Task::(_decref)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::ref 1 aborting True
>> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,246::task::1168::TaskManager.Task::(prepare)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::aborting: Task is aborted: 'Unknown pool
id, pool not connected' - code 309
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,246::task::1173::TaskManager.Task::(prepare)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::Prepare: aborted: Unknown pool id, pool not
connected
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,246::task::990::TaskManager.Task::(_decref)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::ref 0 aborting True
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,246::task::925::TaskManager.Task::(_doAbort)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::Task._doAbort: force False
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,247::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,247::task::595::TaskManager.Task::(_updateState)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::moving from state preparing -> state
aborting
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,247::task::550::TaskManager.Task::(__state_aborting)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::_aborting: recover policy none
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,247::task::595::TaskManager.Task::(_updateState)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::moving from state aborting -> state
failed
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,247::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll
requests {} resources {}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,247::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll
requests {}
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,248::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,311::BindingXMLRPC::251::vds::(wrapper) client [192.168.1.44]
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,312::task::595::TaskManager.Task::(_updateState)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::moving from state init -> state preparing
>> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,312::logUtils::44::dispatcher::(wrapper) Run and protect:
connectStoragePool(spUUID='00000002-0002-0002-0002-0000000000ec', hostID=1,
msdUUID='6bee0e2d-961c-453d-a266-e4623f91e162', masterVersion=1, domainsMap=None,
options=None)
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,313::resourceManager::198::ResourceManager.Request::(__init__)
ResName=`Storage.HsmDomainMonitorLock`ReqID=`bc44804a-eafd-4c6d-9362-4d1b58dbc332`::Request
was made in '/usr/share/vdsm/storage/hsm.py' line '1007' at
'connectStoragePool'
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,313::resourceManager::542::ResourceManager::(registerResource) Trying to register
resource 'Storage.HsmDomainMonitorLock' for lock type 'exclusive'
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,313::resourceManager::601::ResourceManager::(registerResource) Resource
'Storage.HsmDomainMonitorLock' is free. Now locking as 'exclusive' (1
active user)
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,313::resourceManager::238::ResourceManager.Request::(grant)
ResName=`Storage.HsmDomainMonitorLock`ReqID=`bc44804a-eafd-4c6d-9362-4d1b58dbc332`::Granted
request
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,314::resourceManager::198::ResourceManager.Request::(__init__)
ResName=`Storage.00000002-0002-0002-0002-0000000000ec`ReqID=`92d7be18-2aaf-402d-a185-c36818ee5aa4`::Request
was made in '/usr/share/vdsm/storage/hsm.py' line '1055' at
'_connectStoragePool'
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,314::resourceManager::542::ResourceManager::(registerResource) Trying to register
resource 'Storage.00000002-0002-0002-0002-0000000000ec' for lock type
'exclusive'
>> pe 'exclusive'
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,314::resourceManager::601::ResourceManager::(registerResource) Resource
'Storage.00000002-0002-0002-0002-0000000000ec' is free. Now locking as
'exclusive' (1 active user)
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,315::resourceManager::238::ResourceManager.Request::(grant)
ResName=`Storage.00000002-0002-0002-0002-0000000000ec`ReqID=`92d7be18-2aaf-402d-a185-c36818ee5aa4`::Granted
request
>> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,316::sp::133::Storage.StoragePool::(setBackend) updating pool
00000002-0002-0002-0002-0000000000ec backend from type NoneType instance 0x3cd1372210 to
type StoragePoolDiskBackend instance 0x7f84e8062fc8
>> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,316::sp::618::Storage.StoragePool::(connect) Connect host #1 to the storage pool
00000002-0002-0002-0002-0000000000ec with master domain:
6bee0e2d-961c-453d-a266-e4623f91e162 (ver = 1)
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,317::lvm::496::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate
operation' got the operation mutex
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,317::lvm::498::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate
operation' released the operation mutex
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,317::lvm::507::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate
operation' got the operation mutex
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,317::lvm::509::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate
operation' released the operation mutex
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,318::lvm::527::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate
operation' got the operation mutex
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,318::lvm::529::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate
operation' released the operation mutex
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,318::misc::762::SamplingMethod::(__call__) Trying to enter sampling method
(storage.sdc.refreshStorage)
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,318::misc::764::SamplingMethod::(__call__) Got in to sampling method
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,318::misc::762::SamplingMethod::(__call__) Trying to enter sampling method
(storage.iscsi.rescan)
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,318::misc::764::SamplingMethod::(__call__) Got in to sampling method
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,319::iscsi::393::Storage.ISCSI::(rescan) Performing SCSI scan, this will take up
to 30 seconds
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,319::iscsiadm::92::Storage.Misc.excCmd::(_runCmd) '/usr/bin/sudo -n
/sbin/iscsiadm -m session -R' (cwd None)
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,343::misc::772::SamplingMethod::(__call__) Returning last result
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,343::multipath::110::Storage.Misc.excCmd::(rescan) '/usr/bin/sudo -n
/sbin/multipath -r' (cwd None)
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,364::multipath::110::Storage.Misc.excCmd::(rescan) SUCCESS: <err> =
''; <rc> = 0
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,365::lvm::496::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate
operation' got the operation mutex
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,365::lvm::498::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate
operation' released the operation mutex
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,366::lvm::507::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate
operation' got the operation mutex
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,366::lvm::509::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate
operation' released the operation mutex
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,366::lvm::527::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate
operation' got the operation mutex
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,367::lvm::529::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate
operation' released the operation mutex
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,367::misc::772::SamplingMethod::(__call__) Returning last result
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,383::fileSD::140::Storage.StorageDomain::(__init__) Reading domain in path
/rhev/data-center/mnt/192.168.1.44:_raid_ovirt_data/6bee0e2d-961c-453d-a266-e4623f91e162
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,384::persistentDict::192::Storage.PersistentDict::(__init__) Created a persistent
dict with FileMetadataRW backend
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,392::persistentDict::234::Storage.PersistentDict::(refresh) read lines
(FileMetadataRW)=[]
>> vdsm.log.11:Thread-23::WARNING::2014-04-30
15:50:07,392::persistentDict::256::Storage.PersistentDict::(refresh) data has no embedded
checksum - trust it as it is
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,393::resourceManager::616::ResourceManager::(releaseResource) Trying to release
resource 'Storage.00000002-0002-0002-0002-0000000000ec'
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,393::resourceManager::635::ResourceManager::(releaseResource) Released resource
'Storage.00000002-0002-0002-0002-0000000000ec' (0 active users)
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,393::resourceManager::641::ResourceManager::(releaseResource) Resource
'Storage.00000002-0002-0002-0002-0000000000ec' is free, finding out if anyone is
waiting for it.
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,393::resourceManager::649::ResourceManager::(releaseResource) No one is waiting
for resource 'Storage.00000002-0002-0002-0002-0000000000ec', Clearing records.
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,394::resourceManager::616::ResourceManager::(releaseResource) Trying to release
resource 'Storage.HsmDomainMonitorLock'
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,394::resourceManager::635::ResourceManager::(releaseResource) Released resource
'Storage.HsmDomainMonitorLock' (0 active users)
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,394::resourceManager::641::ResourceManager::(releaseResource) Resource
'Storage.HsmDomainMonitorLock' is free, finding out if anyone is waiting for it.
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,395::resourceManager::649::ResourceManager::(releaseResource) No one is waiting
for resource 'Storage.HsmDomainMonitorLock', Clearing records.
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,395::task::866::TaskManager.Task::(_setError)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::Unexpected error
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,396::task::885::TaskManager.Task::(_run)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::Task._run:
b9440814-a49e-446f-bfee-05f3bb3f73fd ('00000002-0002-0002-0002-0000000000ec', 1,
'6bee0e2d-961c-453d-a266-e4623f91e162', 1, None) {} failed - stopping task
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,396::task::1211::TaskManager.Task::(stop)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::stopping in state preparing (force False)
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,396::task::990::TaskManager.Task::(_decref)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::ref 1 aborting True
>> vdsm.log.11:Thread-23::INFO::2014-04-30
15:50:07,397::task::1168::TaskManager.Task::(prepare)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::aborting: Task is aborted:
u"'VERSION'" - code 100
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,397::task::1173::TaskManager.Task::(prepare)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::Prepare: aborted: 'VERSION'
>> vdsm.log.11:Thread-23::DEBUG::2014-04-30
15:50:07,397::task::990::TaskManager.Task::(_decref)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::ref 0 aborting True
> When looking for messages with ERROR or WARNING tags:
>
>
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,150::task::866::TaskManager.Task::(_setError)
Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Unexpected error
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,161::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,178::task::866::TaskManager.Task::(_setError)
Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Unexpected error
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,180::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': 'Not SPM: ()', 'code': 654}}
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,245::task::866::TaskManager.Task::(_setError)
Task=`e4168665-b47d-45f9-8901-727761acbefb`::Unexpected error
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,248::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
>> vdsm.log.11:Thread-23::WARNING::2014-04-30
15:50:07,392::persistentDict::256::Storage.PersistentDict::(refresh) data has no embedded
checksum - trust it as it is
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,395::task::866::TaskManager.Task::(_setError)
Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::Unexpected error
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:07,399::dispatcher::68::Storage.Dispatcher.Protect::(run) 'VERSION'
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,462::task::866::TaskManager.Task::(_setError)
Task=`c107a3de-819b-44c5-8739-f31ea6cc3b91`::Unexpected error
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,465::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,493::task::866::TaskManager.Task::(_setError)
Task=`df7f16b1-72fe-43e9-ab76-7b59a694819e`::Unexpected error
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,496::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': 'Not SPM: ()', 'code': 654}}
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,558::task::866::TaskManager.Task::(_setError)
Task=`68c69145-33b5-4fcb-8c91-47b27edf2d98`::Unexpected error
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,561::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
>> vdsm.log.11:Thread-23::WARNING::2014-04-30
15:50:17,694::persistentDict::256::Storage.PersistentDict::(refresh) data has no embedded
checksum - trust it as it is
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,697::task::866::TaskManager.Task::(_setError)
Task=`f807fd52-5495-4633-8615-b0923ff16e1d`::Unexpected error
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:17,701::dispatcher::68::Storage.Dispatcher.Protect::(run) 'VERSION'
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:27,765::task::866::TaskManager.Task::(_setError)
Task=`5a0268e4-58e4-4e5f-a87a-89da345d373e`::Unexpected error
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:27,768::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:27,786::task::866::TaskManager.Task::(_setError)
Task=`7e2d100d-3670-4b91-b861-9fbd43c5b110`::Unexpected error
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:27,789::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': 'Not SPM: ()', 'code': 654}}
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:27,860::task::866::TaskManager.Task::(_setError)
Task=`833a9952-107a-437a-bc93-99849e0e0612`::Unexpected error
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:27,865::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
>> vdsm.log.11:Thread-23::WARNING::2014-04-30
15:50:28,010::persistentDict::256::Storage.PersistentDict::(refresh) data has no embedded
checksum - trust it as it is
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:28,013::task::866::TaskManager.Task::(_setError)
Task=`e999e46e-9a5f-43ba-881d-145c38fcb18f`::Unexpected error
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:28,017::dispatcher::68::Storage.Dispatcher.Protect::(run) 'VERSION'
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:38,078::task::866::TaskManager.Task::(_setError)
Task=`7d632291-beb9-4bec-9d14-ce9b7d240e49`::Unexpected error
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:38,082::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:38,097::task::866::TaskManager.Task::(_setError)
Task=`1f7a2469-c5f5-460f-a09e-3ff7f666dfe1`::Unexpected error
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:38,101::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': 'Not SPM: ()', 'code': 654}}
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:38,163::task::866::TaskManager.Task::(_setError)
Task=`a793071a-13e2-4c66-8c63-34501c7becec`::Unexpected error
>> vdsm.log.11:Thread-23::ERROR::2014-04-30
15:50:38,166::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status':
{'message': "Unknown pool id, pool not connected:
('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}
>>
>>
>
>
> Thank you very much already.
>
> Boudewijn Ector
> _______________________________________________
> Users mailing list
> Users(a)ovirt.org
> http://lists.ovirt.org/mailman/listinfo/users
Bump, anyone? I'm quite a bit disappointed about the lack of
debugability of ovirt actually.
Cheers,
Boudewijn
_______________________________________________
Users mailing list
Users(a)ovirt.org
http://lists.ovirt.org/mailman/listinfo/users
was this resolved?
3840
days inactive
3859
days old
4 comments
4 participants
participants (4)
-
Boudewijn Ector -
Boudewijn Ector ICT -
Gadi Ickowicz -
Itamar Heim