5:27 a.m.
My cluster appears to be experiencing an SPM problem. I recently placed
each host in maintenance to move the ovirt management network to another
interface. All was successful and all VMs are currently running. However,
I'm not facing an SPM contending loop with data center going in and out of
responsive status.
I have a 3 server HCI setup and all volumes are active and healed, there
are no unsynced entries or split brains.
Does anyone know how I could diagnose the SPM issue?
engine.log:
2020-01-13 22:24:54,777-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterTasksListVDSCommand]
(DefaultQuartzScheduler2) [213adf4f] START,
GlusterTasksListVDSCommand(HostName = Orchard0,
VdsIdVDSCommandParametersBase:{hostId='771c67eb-56e6-4736-8c67-668502d4ecf5'}),
log id: 349f80a9
2020-01-13 22:24:55,231-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterTasksListVDSCommand]
(DefaultQuartzScheduler2) [213adf4f] FINISH, GlusterTasksListVDSCommand,
return: [], log id: 349f80a9
2020-01-13 22:24:58,245-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] START,
GlusterServersListVDSCommand(HostName = Orchard0,
VdsIdVDSCommandParametersBase:{hostId='771c67eb-56e6-4736-8c67-668502d4ecf5'}),
log id: 7b04f110
2020-01-13 22:24:58,887-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Command
'org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand'
return value '
TaskStatusListReturn:{status='Status [code=654, message=Not SPM]'}
'
2020-01-13 22:24:58,888-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] HostName = Orchard1
2020-01-13 22:24:58,888-04 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Command
'HSMGetAllTasksStatusesVDSCommand(HostName = Orchard1,
VdsIdVDSCommandParametersBase:{hostId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d'})'
execution failed: IRSGenericException: IRSErrorException:
IRSNonOperationalException: Not SPM
2020-01-13 22:24:59,034-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] FINISH, GlusterServersListVDSCommand,
return: [10.12.0.220/24:CONNECTED, orchard1.grove.silverorange.com:CONNECTED,
orchard2.grove.silverorange.com:DISCONNECTED], log id: 7b04f110
2020-01-13 22:24:59,049-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] START,
GlusterServersListVDSCommand(HostName = Orchard2,
VdsIdVDSCommandParametersBase:{hostId='fd0752d8-2d41-45b0-887a-0ffacbb8a237'}),
log id: 43f1dd82
2020-01-13 22:24:59,099-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] START,
ConnectStoragePoolVDSCommand(HostName = Orchard1,
ConnectStoragePoolVDSCommandParameters:{hostId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d',
vdsId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d',
storagePoolId='a45e442e-9989-11e8-b0e4-00163e4bf18a',
masterVersion='1'}),
log id: 2b397b31
2020-01-13 22:24:59,099-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Executing with
domain map: {edc68a7c-7604-47e6-89bc-3738d727e8fc=active,
23c22a0f-0482-425e-8ada-730cf8ec0751=active,
390c0320-e843-4ff3-a4bb-a9973058447f=active,
fb43d33a-82c8-44cb-8169-090cd0d8f56e=active,
d70b171e-7488-4d52-8cad-bbc581dbf16e=active,
1f2e9989-9ab3-43d5-971d-568b8feca918=active}
2020-01-13 22:24:59,850-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] FINISH, GlusterServersListVDSCommand,
return: [10.12.0.222/24:CONNECTED, 10.11.0.220:CONNECTED,
orchard1.grove.silverorange.com:CONNECTED], log id: 43f1dd82
2020-01-13 22:24:59,852-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] START,
GlusterVolumesListVDSCommand(HostName = Orchard0,
GlusterVolumesListVDSParameters:{hostId='771c67eb-56e6-4736-8c67-668502d4ecf5'}),
log id: 263be6f8
2020-01-13 22:25:00,019-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] FINISH,
ConnectStoragePoolVDSCommand, return: , log id: 2b397b31
2020-01-13 22:25:00,036-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxy]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) []
hostFromVds::selectedVds - 'Orchard1', spmStatus 'Free', storage pool
'Default', storage pool version '4.3'
2020-01-13 22:25:00,056-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxy]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] starting spm on vds
'Orchard1', storage pool 'Default', prevId '-1', LVER
'-1'
2020-01-13 22:25:00,057-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] START,
SpmStartVDSCommand(HostName = Orchard1,
SpmStartVDSCommandParameters:{hostId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d',
storagePoolId='a45e442e-9989-11e8-b0e4-00163e4bf18a', prevId='-1',
prevLVER='-1', storagePoolFormatType='V4', recoveryMode='Manual',
SCSIFencing='false'}), log id: 3dea111a
2020-01-13 22:25:00,065-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] spmStart polling
started: taskId '671d5904-e062-4d45-9eb4-83a6f13657fe'
2020-01-13 22:25:00,500-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] FINISH, GlusterVolumesListVDSCommand,
return:
{3f8f6a0f-aed4-48e3-9129-18a2a3f64eef=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@743f4102,
71ff56d9-79b8-445d-b637-72ffc974f109=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@cad5f8f4,
752a9438-cd11-426c-b384-bc3c5f86ed07=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@f9f55499,
c3e7447e-8514-4e4a-9ff5-a648fe6aa537=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@7a2c16da,
79e8e93c-57c8-4541-a360-726cec3790cf=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@33e1ab37,
095fd8fc-5322-4741-8805-fc0bb64b554f=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@b28195c0},
log id: 263be6f8
2020-01-13 22:25:03,089-04 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetTaskStatusVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Failed in
'HSMGetTaskStatusVDS' method
2020-01-13 22:25:03,090-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] spmStart polling
ended: taskId '671d5904-e062-4d45-9eb4-83a6f13657fe' task status
'finished'
2020-01-13 22:25:03,090-04 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Start SPM Task
failed - result: 'cleanSuccess', message: VDSGenericException:
VDSErrorException: Failed to HSMGetTaskStatusVDS, error = TaskManager
error, unable to add task: ('Task id already in use:
7df9eeb4-f7a8-4de4-b3f7-5e5607d48dda',), code = 100
2020-01-13 22:25:03,104-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] spmStart polling
ended, spm status: Free
2020-01-13 22:25:03,105-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] START,
HSMClearTaskVDSCommand(HostName = Orchard1,
HSMTaskGuidBaseVDSCommandParameters:{hostId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d',
taskId='671d5904-e062-4d45-9eb4-83a6f13657fe'}), log id: 5335606f
2020-01-13 22:25:03,110-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] FINISH,
HSMClearTaskVDSCommand, return: , log id: 5335606f
2020-01-13 22:25:03,110-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] FINISH,
SpmStartVDSCommand, return: SpmStatusResult:{SPM Id='-1', SPM LVER='-1',
SPM Status='Free'}, log id: 3dea111a
2020-01-13 22:25:03,117-04 INFO
[org.ovirt.engine.core.bll.storage.pool.SetStoragePoolStatusCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac] Running
command: SetStoragePoolStatusCommand internal: true. Entities affected :
ID: a45e442e-9989-11e8-b0e4-00163e4bf18a Type: StoragePool
2020-01-13 22:25:03,179-04 ERROR
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac]
IrsBroker::Failed::GetStoragePoolInfoVDS: IRSGenericException:
IRSErrorException: SpmStart failed
2020-01-13 22:25:03,205-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxy]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac] Irs placed
on server 'fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d' failed. Proceed Failover
2020-01-13 22:25:03,223-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac] START,
ConnectStoragePoolVDSCommand(HostName = Orchard2,
ConnectStoragePoolVDSCommandParameters:{hostId='fd0752d8-2d41-45b0-887a-0ffacbb8a237',
vdsId='fd0752d8-2d41-45b0-887a-0ffacbb8a237',
storagePoolId='a45e442e-9989-11e8-b0e4-00163e4bf18a',
masterVersion='1'}),
log id: 6a7302e9
2020-01-13 22:25:03,224-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac] Executing
with domain map: {edc68a7c-7604-47e6-89bc-3738d727e8fc=active,
23c22a0f-0482-425e-8ada-730cf8ec0751=active,
390c0320-e843-4ff3-a4bb-a9973058447f=active,
fb43d33a-82c8-44cb-8169-090cd0d8f56e=active,
d70b171e-7488-4d52-8cad-bbc581dbf16e=active,
1f2e9989-9ab3-43d5-971d-568b8feca918=active}
-----------------------------
vdsm.log from one of my hosts:
2020-01-13 22:26:12,434-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,435-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 88772af7-8cf5-433e-8be3-8d0adf0bbf04
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py", line
214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 746,
in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 696,
in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs[n], Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/88772af7-8cf5-433e-8be3-8d0adf0bbf04/88772af7-8cf5-433e-8be3-8d0adf0bbf04.job.0',)
2020-01-13 22:26:12,462-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,462-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: a9b11e33-9b93-46a0-a36e-85063fd53ebe
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py", line
214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 751,
in _load
self._loadRecoveryMetaFile(taskDir, rn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 705,
in _loadRecoveryMetaFile
self._loadMetaFile(taskFile, self.recoveries[n], Recovery.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/a9b11e33-9b93-46a0-a36e-85063fd53ebe/a9b11e33-9b93-46a0-a36e-85063fd53ebe.recover.0',)
2020-01-13 22:26:12,476-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,476-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 650f2df4-6489-47e2-af5d-db86a22f01c0
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py", line
214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 751,
in _load
self._loadRecoveryMetaFile(taskDir, rn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 705,
in _loadRecoveryMetaFile
self._loadMetaFile(taskFile, self.recoveries[n], Recovery.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/650f2df4-6489-47e2-af5d-db86a22f01c0/650f2df4-6489-47e2-af5d-db86a22f01c0.recover.0',)
2020-01-13 22:26:12,487-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,488-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: a2e86fcc-8e7e-4e6d-bf5e-5ac61a98169e
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py", line
214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 746,
in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 696,
in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs[n], Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/a2e86fcc-8e7e-4e6d-bf5e-5ac61a98169e/a2e86fcc-8e7e-4e6d-bf5e-5ac61a98169e.job.0',)
2020-01-13 22:26:12,493-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,493-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: eb8b4f7a-9b5c-46f6-aaa7-7ef05dbf1743
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py", line
214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 737,
in _load
self._loadTaskMetaFile(taskDir)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 688,
in _loadTaskMetaFile
self._loadMetaFile(taskFile, self, Task.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/eb8b4f7a-9b5c-46f6-aaa7-7ef05dbf1743/eb8b4f7a-9b5c-46f6-aaa7-7ef05dbf1743.task',)
2020-01-13 22:26:12,505-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,506-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 75318d21-45b2-4dbd-985c-a7851a10a463
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py", line
214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 746,
in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 696,
in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs[n], Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/75318d21-45b2-4dbd-985c-a7851a10a463/75318d21-45b2-4dbd-985c-a7851a10a463.job.0',)
2020-01-13 22:26:12,517-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,517-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 1779b352-022c-49a3-9388-2f688d33cdab
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py", line
214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 746,
in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 696,
in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs[n], Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/1779b352-022c-49a3-9388-2f688d33cdab/1779b352-022c-49a3-9388-2f688d33cdab.job.0',)
2020-01-13 22:26:12,532-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,532-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 0302036a-7d99-4685-befb-6fee1602feaf
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py", line
214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 746,
in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 696,
in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs[n], Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/0302036a-7d99-4685-befb-6fee1602feaf/0302036a-7d99-4685-befb-6fee1602feaf.job.0',)
2020-01-13 22:26:12,545-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,546-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 24a825b9-d48d-4134-8aa1-b4db7a9c6ab1
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py", line
214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 737,
in _load
self._loadTaskMetaFile(taskDir)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 688,
in _loadTaskMetaFile
self._loadMetaFile(taskFile, self, Task.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/24a825b9-d48d-4134-8aa1-b4db7a9c6ab1.backup/24a825b9-d48d-4134-8aa1-b4db7a9c6ab1.task',)
2020-01-13 22:26:12,560-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,561-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 90d88529-a051-4acd-bef2-d0aa034c15de
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py", line
214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 751,
in _load
self._loadRecoveryMetaFile(taskDir, rn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 705,
in _loadRecoveryMetaFile
self._loadMetaFile(taskFile, self.recoveries[n], Recovery.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/90d88529-a051-4acd-bef2-d0aa034c15de/90d88529-a051-4acd-bef2-d0aa034c15de.recover.0',)
2020-01-13 22:26:12,607-0400 ERROR (tasks/5) [storage.StoragePool]
Unexpected error (sp:383)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/sp.py", line 378, in
startSpm
self.taskMng.recoverDumpedTasks()
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py", line
227, in recoverDumpedTasks
self.queueRecovery(task)
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py", line
48, in queueRecovery
return self._queueTask(task, task.recover)
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py", line
54, in _queueTask
'Task id already in use: {0}'.format(task.id))
AddTaskError: TaskManager error, unable to add task: ('Task id already in
use: 7df9eeb4-f7a8-4de4-b3f7-5e5607d48dda',)
2020-01-13 22:26:12,608-0400 ERROR (tasks/5) [storage.StoragePool] failed:
TaskManager error, unable to add task: ('Task id already in use:
7df9eeb4-f7a8-4de4-b3f7-5e5607d48dda',) (sp:384)
2020-01-13 22:26:12,635-0400 ERROR (tasks/5) [storage.TaskManager.Task]
(Task='3c7de2a0-597c-4ebe-b4de-689dba26045b') Unexpected error (task:875)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 882,
in _run
return fn(*args, **kargs)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 336,
in run
return self.cmd(*self.argslist, **self.argsdict)
File "/usr/lib/python2.7/site-packages/vdsm/storage/sp.py", line 378, in
startSpm
self.taskMng.recoverDumpedTasks()
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py", line
227, in recoverDumpedTasks
self.queueRecovery(task)
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py", line
48, in queueRecovery
return self._queueTask(task, task.recover)
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py", line
54, in _queueTask
'Task id already in use: {0}'.format(task.id))
AddTaskError: TaskManager error, unable to add task: ('Task id already in
use: 7df9eeb4-f7a8-4de4-b3f7-5e5607d48dda',)
12:46 p.m.
On Tue, Jan 14, 2020 at 4:33 AM Jayme <jaymef(a)gmail.com> wrote:
My cluster appears to be experiencing an SPM problem. I recently
placed
each host in maintenance to move the ovirt management network to another
interface. All was successful and all VMs are currently running. However,
I'm not facing an SPM contending loop with data center going in and out of
responsive status.
I have a 3 server HCI setup and all volumes are active and healed, there
are no unsynced entries or split brains.
Does anyone know how I could diagnose the SPM issue?
Can you please try to select the host from web admin and make it SPM
manually ???
engine.log:
2020-01-13 22:24:54,777-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterTasksListVDSCommand]
(DefaultQuartzScheduler2) [213adf4f] START,
GlusterTasksListVDSCommand(HostName = Orchard0,
VdsIdVDSCommandParametersBase:{hostId='771c67eb-56e6-4736-8c67-668502d4ecf5'}),
log id: 349f80a9
2020-01-13 22:24:55,231-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterTasksListVDSCommand]
(DefaultQuartzScheduler2) [213adf4f] FINISH, GlusterTasksListVDSCommand,
return: [], log id: 349f80a9
2020-01-13 22:24:58,245-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] START,
GlusterServersListVDSCommand(HostName = Orchard0,
VdsIdVDSCommandParametersBase:{hostId='771c67eb-56e6-4736-8c67-668502d4ecf5'}),
log id: 7b04f110
2020-01-13 22:24:58,887-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Command
'org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand'
return value '
TaskStatusListReturn:{status='Status [code=654, message=Not SPM]'}
'
2020-01-13 22:24:58,888-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] HostName = Orchard1
2020-01-13 22:24:58,888-04 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Command
'HSMGetAllTasksStatusesVDSCommand(HostName = Orchard1,
VdsIdVDSCommandParametersBase:{hostId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d'})'
execution failed: IRSGenericException: IRSErrorException:
IRSNonOperationalException: Not SPM
2020-01-13 22:24:59,034-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] FINISH, GlusterServersListVDSCommand,
return: [10.12.0.220/24:CONNECTED, orchard1.grove.silverorange.com:CONNECTED,
orchard2.grove.silverorange.com:DISCONNECTED], log id: 7b04f110
2020-01-13 22:24:59,049-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] START,
GlusterServersListVDSCommand(HostName = Orchard2,
VdsIdVDSCommandParametersBase:{hostId='fd0752d8-2d41-45b0-887a-0ffacbb8a237'}),
log id: 43f1dd82
2020-01-13 22:24:59,099-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] START,
ConnectStoragePoolVDSCommand(HostName = Orchard1,
ConnectStoragePoolVDSCommandParameters:{hostId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d',
vdsId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d',
storagePoolId='a45e442e-9989-11e8-b0e4-00163e4bf18a',
masterVersion='1'}),
log id: 2b397b31
2020-01-13 22:24:59,099-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Executing with
domain map: {edc68a7c-7604-47e6-89bc-3738d727e8fc=active,
23c22a0f-0482-425e-8ada-730cf8ec0751=active,
390c0320-e843-4ff3-a4bb-a9973058447f=active,
fb43d33a-82c8-44cb-8169-090cd0d8f56e=active,
d70b171e-7488-4d52-8cad-bbc581dbf16e=active,
1f2e9989-9ab3-43d5-971d-568b8feca918=active}
2020-01-13 22:24:59,850-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] FINISH, GlusterServersListVDSCommand,
return: [10.12.0.222/24:CONNECTED, 10.11.0.220:CONNECTED,
orchard1.grove.silverorange.com:CONNECTED], log id: 43f1dd82
2020-01-13 22:24:59,852-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] START,
GlusterVolumesListVDSCommand(HostName = Orchard0,
GlusterVolumesListVDSParameters:{hostId='771c67eb-56e6-4736-8c67-668502d4ecf5'}),
log id: 263be6f8
2020-01-13 22:25:00,019-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] FINISH,
ConnectStoragePoolVDSCommand, return: , log id: 2b397b31
2020-01-13 22:25:00,036-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxy]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) []
hostFromVds::selectedVds - 'Orchard1', spmStatus 'Free', storage pool
'Default', storage pool version '4.3'
2020-01-13 22:25:00,056-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxy]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] starting spm on vds
'Orchard1', storage pool 'Default', prevId '-1', LVER
'-1'
2020-01-13 22:25:00,057-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] START,
SpmStartVDSCommand(HostName = Orchard1,
SpmStartVDSCommandParameters:{hostId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d',
storagePoolId='a45e442e-9989-11e8-b0e4-00163e4bf18a', prevId='-1',
prevLVER='-1', storagePoolFormatType='V4',
recoveryMode='Manual',
SCSIFencing='false'}), log id: 3dea111a
2020-01-13 22:25:00,065-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] spmStart polling
started: taskId '671d5904-e062-4d45-9eb4-83a6f13657fe'
2020-01-13 22:25:00,500-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] FINISH, GlusterVolumesListVDSCommand,
return:
{3f8f6a0f-aed4-48e3-9129-18a2a3f64eef=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@743f4102,
71ff56d9-79b8-445d-b637-72ffc974f109=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@cad5f8f4,
752a9438-cd11-426c-b384-bc3c5f86ed07=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@f9f55499,
c3e7447e-8514-4e4a-9ff5-a648fe6aa537=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@7a2c16da,
79e8e93c-57c8-4541-a360-726cec3790cf=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@33e1ab37,
095fd8fc-5322-4741-8805-fc0bb64b554f=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@b28195c0},
log id: 263be6f8
2020-01-13 22:25:03,089-04 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetTaskStatusVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Failed in
'HSMGetTaskStatusVDS' method
2020-01-13 22:25:03,090-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] spmStart polling
ended: taskId '671d5904-e062-4d45-9eb4-83a6f13657fe' task status
'finished'
2020-01-13 22:25:03,090-04 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Start SPM Task
failed - result: 'cleanSuccess', message: VDSGenericException:
VDSErrorException: Failed to HSMGetTaskStatusVDS, error = TaskManager
error, unable to add task: ('Task id already in use:
7df9eeb4-f7a8-4de4-b3f7-5e5607d48dda',), code = 100
2020-01-13 22:25:03,104-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] spmStart polling
ended, spm status: Free
2020-01-13 22:25:03,105-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] START,
HSMClearTaskVDSCommand(HostName = Orchard1,
HSMTaskGuidBaseVDSCommandParameters:{hostId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d',
taskId='671d5904-e062-4d45-9eb4-83a6f13657fe'}), log id: 5335606f
2020-01-13 22:25:03,110-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] FINISH,
HSMClearTaskVDSCommand, return: , log id: 5335606f
2020-01-13 22:25:03,110-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] FINISH,
SpmStartVDSCommand, return: SpmStatusResult:{SPM Id='-1', SPM LVER='-1',
SPM Status='Free'}, log id: 3dea111a
2020-01-13 22:25:03,117-04 INFO
[org.ovirt.engine.core.bll.storage.pool.SetStoragePoolStatusCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac] Running
command: SetStoragePoolStatusCommand internal: true. Entities affected :
ID: a45e442e-9989-11e8-b0e4-00163e4bf18a Type: StoragePool
2020-01-13 22:25:03,179-04 ERROR
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac]
IrsBroker::Failed::GetStoragePoolInfoVDS: IRSGenericException:
IRSErrorException: SpmStart failed
2020-01-13 22:25:03,205-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxy]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac] Irs placed
on server 'fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d' failed. Proceed Failover
2020-01-13 22:25:03,223-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac] START,
ConnectStoragePoolVDSCommand(HostName = Orchard2,
ConnectStoragePoolVDSCommandParameters:{hostId='fd0752d8-2d41-45b0-887a-0ffacbb8a237',
vdsId='fd0752d8-2d41-45b0-887a-0ffacbb8a237',
storagePoolId='a45e442e-9989-11e8-b0e4-00163e4bf18a',
masterVersion='1'}),
log id: 6a7302e9
2020-01-13 22:25:03,224-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac] Executing
with domain map: {edc68a7c-7604-47e6-89bc-3738d727e8fc=active,
23c22a0f-0482-425e-8ada-730cf8ec0751=active,
390c0320-e843-4ff3-a4bb-a9973058447f=active,
fb43d33a-82c8-44cb-8169-090cd0d8f56e=active,
d70b171e-7488-4d52-8cad-bbc581dbf16e=active,
1f2e9989-9ab3-43d5-971d-568b8feca918=active}
-----------------------------
vdsm.log from one of my hosts:
2020-01-13 22:26:12,434-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,435-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 88772af7-8cf5-433e-8be3-8d0adf0bbf04
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 746,
in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 696,
in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs[n], Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/88772af7-8cf5-433e-8be3-8d0adf0bbf04/88772af7-8cf5-433e-8be3-8d0adf0bbf04.job.0',)
2020-01-13 22:26:12,462-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,462-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: a9b11e33-9b93-46a0-a36e-85063fd53ebe
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 751,
in _load
self._loadRecoveryMetaFile(taskDir, rn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 705,
in _loadRecoveryMetaFile
self._loadMetaFile(taskFile, self.recoveries[n], Recovery.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/a9b11e33-9b93-46a0-a36e-85063fd53ebe/a9b11e33-9b93-46a0-a36e-85063fd53ebe.recover.0',)
2020-01-13 22:26:12,476-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,476-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 650f2df4-6489-47e2-af5d-db86a22f01c0
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 751,
in _load
self._loadRecoveryMetaFile(taskDir, rn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 705,
in _loadRecoveryMetaFile
self._loadMetaFile(taskFile, self.recoveries[n], Recovery.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/650f2df4-6489-47e2-af5d-db86a22f01c0/650f2df4-6489-47e2-af5d-db86a22f01c0.recover.0',)
2020-01-13 22:26:12,487-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,488-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: a2e86fcc-8e7e-4e6d-bf5e-5ac61a98169e
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 746,
in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 696,
in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs[n], Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/a2e86fcc-8e7e-4e6d-bf5e-5ac61a98169e/a2e86fcc-8e7e-4e6d-bf5e-5ac61a98169e.job.0',)
2020-01-13 22:26:12,493-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,493-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: eb8b4f7a-9b5c-46f6-aaa7-7ef05dbf1743
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 737,
in _load
self._loadTaskMetaFile(taskDir)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 688,
in _loadTaskMetaFile
self._loadMetaFile(taskFile, self, Task.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/eb8b4f7a-9b5c-46f6-aaa7-7ef05dbf1743/eb8b4f7a-9b5c-46f6-aaa7-7ef05dbf1743.task',)
2020-01-13 22:26:12,505-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,506-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 75318d21-45b2-4dbd-985c-a7851a10a463
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 746,
in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 696,
in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs[n], Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/75318d21-45b2-4dbd-985c-a7851a10a463/75318d21-45b2-4dbd-985c-a7851a10a463.job.0',)
2020-01-13 22:26:12,517-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,517-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 1779b352-022c-49a3-9388-2f688d33cdab
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 746,
in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 696,
in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs[n], Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/1779b352-022c-49a3-9388-2f688d33cdab/1779b352-022c-49a3-9388-2f688d33cdab.job.0',)
2020-01-13 22:26:12,532-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,532-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 0302036a-7d99-4685-befb-6fee1602feaf
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 746,
in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 696,
in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs[n], Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/0302036a-7d99-4685-befb-6fee1602feaf/0302036a-7d99-4685-befb-6fee1602feaf.job.0',)
2020-01-13 22:26:12,545-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,546-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 24a825b9-d48d-4134-8aa1-b4db7a9c6ab1
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 737,
in _load
self._loadTaskMetaFile(taskDir)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 688,
in _loadTaskMetaFile
self._loadMetaFile(taskFile, self, Task.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/24a825b9-d48d-4134-8aa1-b4db7a9c6ab1.backup/24a825b9-d48d-4134-8aa1-b4db7a9c6ab1.task',)
2020-01-13 22:26:12,560-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,561-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 90d88529-a051-4acd-bef2-d0aa034c15de
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 751,
in _load
self._loadRecoveryMetaFile(taskDir, rn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 705,
in _loadRecoveryMetaFile
self._loadMetaFile(taskFile, self.recoveries[n], Recovery.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/90d88529-a051-4acd-bef2-d0aa034c15de/90d88529-a051-4acd-bef2-d0aa034c15de.recover.0',)
2020-01-13 22:26:12,607-0400 ERROR (tasks/5) [storage.StoragePool]
Unexpected error (sp:383)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/sp.py", line 378, in
startSpm
self.taskMng.recoverDumpedTasks()
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 227, in recoverDumpedTasks
self.queueRecovery(task)
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 48, in queueRecovery
return self._queueTask(task, task.recover)
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 54, in _queueTask
'Task id already in use: {0}'.format(task.id))
AddTaskError: TaskManager error, unable to add task: ('Task id already in
use: 7df9eeb4-f7a8-4de4-b3f7-5e5607d48dda',)
2020-01-13 22:26:12,608-0400 ERROR (tasks/5) [storage.StoragePool] failed:
TaskManager error, unable to add task: ('Task id already in use:
7df9eeb4-f7a8-4de4-b3f7-5e5607d48dda',) (sp:384)
2020-01-13 22:26:12,635-0400 ERROR (tasks/5) [storage.TaskManager.Task]
(Task='3c7de2a0-597c-4ebe-b4de-689dba26045b') Unexpected error (task:875)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 882,
in _run
return fn(*args, **kargs)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 336,
in run
return self.cmd(*self.argslist, **self.argsdict)
File "/usr/lib/python2.7/site-packages/vdsm/storage/sp.py", line 378, in
startSpm
self.taskMng.recoverDumpedTasks()
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 227, in recoverDumpedTasks
self.queueRecovery(task)
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 48, in queueRecovery
return self._queueTask(task, task.recover)
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 54, in _queueTask
'Task id already in use: {0}'.format(task.id))
AddTaskError: TaskManager error, unable to add task: ('Task id already in
use: 7df9eeb4-f7a8-4de4-b3f7-5e5607d48dda',)
_______________________________________________
Users mailing list -- users(a)ovirt.org
To unsubscribe send an email to users-leave(a)ovirt.org
Privacy Statement: https://www.ovirt.org/site/privacy-policy/
oVirt Code of Conduct:
https://www.ovirt.org/community/about/community-guidelines/
List Archives:
https://lists.ovirt.org/archives/list/users@ovirt.org/message/5XPGERTWVSX...
1 p.m.
Hi Jayme,
The only thing I can find related to the vdsm errors you post is
https://bugzilla.redhat.com/show_bug.cgi?id=1493184
Nir states it's just a logging issue so that doesn't help to much.
What version are you running?
Anything in the gluster logs on the node?
Nir Soffer 2018-06-25 12:27:16 UTC
These exceptions:
OSError: [Errno 2] No such file or directory
...
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/e6c5d8a2-5386-11e8-8885-004655214801/mastersd/master/tasks/60bf8af9-d4d3-4753-a40d-2a8d028d3d3c/60bf8af9-d4d3-4753-a40d-2a8d028d3d3c.recover.0',)
Mean that a dumped task could not not loaded because there was no such file in the
task directory.
This error does not effect the SPM start process, the code is trying to load dumped
tasks and ignore the result of the load.
So this looks like log issue, moving severity to low since I don't see any real
issue.
Regarding the exceptions, we have several issues:
1. Logging several exceptions for the same problem - we should log the same issue
exactly once. This happens because the code using the anti-pattern of logging
an exception and raising new one.
2. I'm not sure why we log a traceback for expected error like a missing dumped
task file. This should be logged without a traceback.
3. I'm not sure why missing dumped task is an error, since the SPM code ignore
it. This should be probably a warning.
Regards,
Jorick Astrego
Netbulae
On 1/14/20 3:27 AM, Jayme wrote:
My cluster appears to be experiencing an SPM problem. I recently
placed each host in maintenance to move the ovirt management network
to another interface. All was successful and all VMs are currently
running. However, I'm not facing an SPM contending loop with data
center going in and out of responsive status.
I have a 3 server HCI setup and all volumes are active and healed,
there are no unsynced entries or split brains.
Does anyone know how I could diagnose the SPM issue?
engine.log:
2020-01-13 22:24:54,777-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterTasksListVDSCommand]
(DefaultQuartzScheduler2) [213adf4f] START,
GlusterTasksListVDSCommand(HostName = Orchard0,
VdsIdVDSCommandParametersBase:{hostId='771c67eb-56e6-4736-8c67-668502d4ecf5'}),
log id: 349f80a9
2020-01-13 22:24:55,231-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterTasksListVDSCommand]
(DefaultQuartzScheduler2) [213adf4f] FINISH,
GlusterTasksListVDSCommand, return: [], log id: 349f80a9
2020-01-13 22:24:58,245-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] START,
GlusterServersListVDSCommand(HostName = Orchard0,
VdsIdVDSCommandParametersBase:{hostId='771c67eb-56e6-4736-8c67-668502d4ecf5'}),
log id: 7b04f110
2020-01-13 22:24:58,887-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Command
'org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand'
return value '
TaskStatusListReturn:{status='Status [code=654, message=Not SPM]'}
'
2020-01-13 22:24:58,888-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] HostName = Orchard1
2020-01-13 22:24:58,888-04 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Command
'HSMGetAllTasksStatusesVDSCommand(HostName = Orchard1,
VdsIdVDSCommandParametersBase:{hostId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d'})'
execution failed: IRSGenericException: IRSErrorException:
IRSNonOperationalException: Not SPM
2020-01-13 22:24:59,034-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] FINISH,
GlusterServersListVDSCommand, return: [10.12.0.220/24:CONNECTED
<http://10.12.0.220/24:CONNECTED>;,
orchard1.grove.silverorange.com:CONNECTED,
orchard2.grove.silverorange.com:DISCONNECTED], log id: 7b04f110
2020-01-13 22:24:59,049-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] START,
GlusterServersListVDSCommand(HostName = Orchard2,
VdsIdVDSCommandParametersBase:{hostId='fd0752d8-2d41-45b0-887a-0ffacbb8a237'}),
log id: 43f1dd82
2020-01-13 22:24:59,099-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] START,
ConnectStoragePoolVDSCommand(HostName = Orchard1,
ConnectStoragePoolVDSCommandParameters:{hostId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d',
vdsId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d',
storagePoolId='a45e442e-9989-11e8-b0e4-00163e4bf18a',
masterVersion='1'}), log id: 2b397b31
2020-01-13 22:24:59,099-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Executing with
domain map: {edc68a7c-7604-47e6-89bc-3738d727e8fc=active,
23c22a0f-0482-425e-8ada-730cf8ec0751=active,
390c0320-e843-4ff3-a4bb-a9973058447f=active,
fb43d33a-82c8-44cb-8169-090cd0d8f56e=active,
d70b171e-7488-4d52-8cad-bbc581dbf16e=active,
1f2e9989-9ab3-43d5-971d-568b8feca918=active}
2020-01-13 22:24:59,850-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] FINISH,
GlusterServersListVDSCommand, return: [10.12.0.222/24:CONNECTED
<http://10.12.0.222/24:CONNECTED>;, 10.11.0.220:CONNECTED,
orchard1.grove.silverorange.com:CONNECTED], log id: 43f1dd82
2020-01-13 22:24:59,852-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] START,
GlusterVolumesListVDSCommand(HostName = Orchard0,
GlusterVolumesListVDSParameters:{hostId='771c67eb-56e6-4736-8c67-668502d4ecf5'}),
log id: 263be6f8
2020-01-13 22:25:00,019-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] FINISH,
ConnectStoragePoolVDSCommand, return: , log id: 2b397b31
2020-01-13 22:25:00,036-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxy]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) []
hostFromVds::selectedVds - 'Orchard1', spmStatus 'Free', storage pool
'Default', storage pool version '4.3'
2020-01-13 22:25:00,056-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxy]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] starting spm on
vds 'Orchard1', storage pool 'Default', prevId '-1', LVER
'-1'
2020-01-13 22:25:00,057-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] START,
SpmStartVDSCommand(HostName = Orchard1,
SpmStartVDSCommandParameters:{hostId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d',
storagePoolId='a45e442e-9989-11e8-b0e4-00163e4bf18a', prevId='-1',
prevLVER='-1', storagePoolFormatType='V4',
recoveryMode='Manual',
SCSIFencing='false'}), log id: 3dea111a
2020-01-13 22:25:00,065-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] spmStart
polling started: taskId '671d5904-e062-4d45-9eb4-83a6f13657fe'
2020-01-13 22:25:00,500-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] FINISH,
GlusterVolumesListVDSCommand, return:
{3f8f6a0f-aed4-48e3-9129-18a2a3f64eef=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@743f4102,
71ff56d9-79b8-445d-b637-72ffc974f109=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@cad5f8f4,
752a9438-cd11-426c-b384-bc3c5f86ed07=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@f9f55499,
c3e7447e-8514-4e4a-9ff5-a648fe6aa537=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@7a2c16da,
79e8e93c-57c8-4541-a360-726cec3790cf=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@33e1ab37,
095fd8fc-5322-4741-8805-fc0bb64b554f=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@b28195c0},
log id: 263be6f8
2020-01-13 22:25:03,089-04 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetTaskStatusVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Failed in
'HSMGetTaskStatusVDS' method
2020-01-13 22:25:03,090-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] spmStart
polling ended: taskId '671d5904-e062-4d45-9eb4-83a6f13657fe' task
status 'finished'
2020-01-13 22:25:03,090-04 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Start SPM Task
failed - result: 'cleanSuccess', message: VDSGenericException:
VDSErrorException: Failed to HSMGetTaskStatusVDS, error = TaskManager
error, unable to add task: ('Task id already in use:
7df9eeb4-f7a8-4de4-b3f7-5e5607d48dda',), code = 100
2020-01-13 22:25:03,104-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] spmStart
polling ended, spm status: Free
2020-01-13 22:25:03,105-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] START,
HSMClearTaskVDSCommand(HostName = Orchard1,
HSMTaskGuidBaseVDSCommandParameters:{hostId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d',
taskId='671d5904-e062-4d45-9eb4-83a6f13657fe'}), log id: 5335606f
2020-01-13 22:25:03,110-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] FINISH,
HSMClearTaskVDSCommand, return: , log id: 5335606f
2020-01-13 22:25:03,110-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] FINISH,
SpmStartVDSCommand, return: SpmStatusResult:{SPM Id='-1', SPM
LVER='-1', SPM Status='Free'}, log id: 3dea111a
2020-01-13 22:25:03,117-04 INFO
[org.ovirt.engine.core.bll.storage.pool.SetStoragePoolStatusCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac] Running
command: SetStoragePoolStatusCommand internal: true. Entities affected
: ID: a45e442e-9989-11e8-b0e4-00163e4bf18a Type: StoragePool
2020-01-13 22:25:03,179-04 ERROR
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac]
IrsBroker::Failed::GetStoragePoolInfoVDS: IRSGenericException:
IRSErrorException: SpmStart failed
2020-01-13 22:25:03,205-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxy]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac] Irs
placed on server 'fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d' failed.
Proceed Failover
2020-01-13 22:25:03,223-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac] START,
ConnectStoragePoolVDSCommand(HostName = Orchard2,
ConnectStoragePoolVDSCommandParameters:{hostId='fd0752d8-2d41-45b0-887a-0ffacbb8a237',
vdsId='fd0752d8-2d41-45b0-887a-0ffacbb8a237',
storagePoolId='a45e442e-9989-11e8-b0e4-00163e4bf18a',
masterVersion='1'}), log id: 6a7302e9
2020-01-13 22:25:03,224-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac]
Executing with domain map:
{edc68a7c-7604-47e6-89bc-3738d727e8fc=active,
23c22a0f-0482-425e-8ada-730cf8ec0751=active,
390c0320-e843-4ff3-a4bb-a9973058447f=active,
fb43d33a-82c8-44cb-8169-090cd0d8f56e=active,
d70b171e-7488-4d52-8cad-bbc581dbf16e=active,
1f2e9989-9ab3-43d5-971d-568b8feca918=active}
-----------------------------
vdsm.log from one of my hosts:
2020-01-13 22:26:12,434-0400 ERROR (tasks/5)
[storage.TaskManager.Task] Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
631, in _loadMetaFile
for line in getProcPool().readLines(filename):
File
"/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py", line
334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
555, in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
543, in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
448, in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,435-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 88772af7-8cf5-433e-8be3-8d0adf0bbf04
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
1162, in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
746, in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
696, in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs <http://self.jobs>[n],
Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
653, in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/88772af7-8cf5-433e-8be3-8d0adf0bbf04/88772af7-8cf5-433e-8be3-8d0adf0bbf04.job.0',)
2020-01-13 22:26:12,462-0400 ERROR (tasks/5)
[storage.TaskManager.Task] Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
631, in _loadMetaFile
for line in getProcPool().readLines(filename):
File
"/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py", line
334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
555, in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
543, in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
448, in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,462-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: a9b11e33-9b93-46a0-a36e-85063fd53ebe
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
1162, in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
751, in _load
self._loadRecoveryMetaFile(taskDir, rn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
705, in _loadRecoveryMetaFile
self._loadMetaFile(taskFile, self.recoveries[n], Recovery.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
653, in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/a9b11e33-9b93-46a0-a36e-85063fd53ebe/a9b11e33-9b93-46a0-a36e-85063fd53ebe.recover.0',)
2020-01-13 22:26:12,476-0400 ERROR (tasks/5)
[storage.TaskManager.Task] Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
631, in _loadMetaFile
for line in getProcPool().readLines(filename):
File
"/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py", line
334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
555, in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
543, in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
448, in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,476-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 650f2df4-6489-47e2-af5d-db86a22f01c0
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
1162, in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
751, in _load
self._loadRecoveryMetaFile(taskDir, rn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
705, in _loadRecoveryMetaFile
self._loadMetaFile(taskFile, self.recoveries[n], Recovery.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
653, in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/650f2df4-6489-47e2-af5d-db86a22f01c0/650f2df4-6489-47e2-af5d-db86a22f01c0.recover.0',)
2020-01-13 22:26:12,487-0400 ERROR (tasks/5)
[storage.TaskManager.Task] Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
631, in _loadMetaFile
for line in getProcPool().readLines(filename):
File
"/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py", line
334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
555, in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
543, in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
448, in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,488-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: a2e86fcc-8e7e-4e6d-bf5e-5ac61a98169e
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
1162, in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
746, in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
696, in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs <http://self.jobs>[n],
Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
653, in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/a2e86fcc-8e7e-4e6d-bf5e-5ac61a98169e/a2e86fcc-8e7e-4e6d-bf5e-5ac61a98169e.job.0',)
2020-01-13 22:26:12,493-0400 ERROR (tasks/5)
[storage.TaskManager.Task] Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
631, in _loadMetaFile
for line in getProcPool().readLines(filename):
File
"/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py", line
334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
555, in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
543, in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
448, in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,493-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: eb8b4f7a-9b5c-46f6-aaa7-7ef05dbf1743
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
1162, in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
737, in _load
self._loadTaskMetaFile(taskDir)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
688, in _loadTaskMetaFile
self._loadMetaFile(taskFile, self, Task.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
653, in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/eb8b4f7a-9b5c-46f6-aaa7-7ef05dbf1743/eb8b4f7a-9b5c-46f6-aaa7-7ef05dbf1743.task',)
2020-01-13 22:26:12,505-0400 ERROR (tasks/5)
[storage.TaskManager.Task] Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
631, in _loadMetaFile
for line in getProcPool().readLines(filename):
File
"/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py", line
334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
555, in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
543, in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
448, in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,506-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 75318d21-45b2-4dbd-985c-a7851a10a463
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
1162, in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
746, in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
696, in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs <http://self.jobs>[n],
Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
653, in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/75318d21-45b2-4dbd-985c-a7851a10a463/75318d21-45b2-4dbd-985c-a7851a10a463.job.0',)
2020-01-13 22:26:12,517-0400 ERROR (tasks/5)
[storage.TaskManager.Task] Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
631, in _loadMetaFile
for line in getProcPool().readLines(filename):
File
"/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py", line
334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
555, in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
543, in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
448, in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,517-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 1779b352-022c-49a3-9388-2f688d33cdab
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
1162, in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
746, in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
696, in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs <http://self.jobs>[n],
Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
653, in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/1779b352-022c-49a3-9388-2f688d33cdab/1779b352-022c-49a3-9388-2f688d33cdab.job.0',)
2020-01-13 22:26:12,532-0400 ERROR (tasks/5)
[storage.TaskManager.Task] Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
631, in _loadMetaFile
for line in getProcPool().readLines(filename):
File
"/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py", line
334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
555, in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
543, in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
448, in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,532-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 0302036a-7d99-4685-befb-6fee1602feaf
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
1162, in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
746, in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
696, in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs <http://self.jobs>[n],
Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
653, in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/0302036a-7d99-4685-befb-6fee1602feaf/0302036a-7d99-4685-befb-6fee1602feaf.job.0',)
2020-01-13 22:26:12,545-0400 ERROR (tasks/5)
[storage.TaskManager.Task] Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
631, in _loadMetaFile
for line in getProcPool().readLines(filename):
File
"/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py", line
334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
555, in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
543, in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
448, in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,546-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 24a825b9-d48d-4134-8aa1-b4db7a9c6ab1
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
1162, in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
737, in _load
self._loadTaskMetaFile(taskDir)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
688, in _loadTaskMetaFile
self._loadMetaFile(taskFile, self, Task.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
653, in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/24a825b9-d48d-4134-8aa1-b4db7a9c6ab1.backup/24a825b9-d48d-4134-8aa1-b4db7a9c6ab1.task',)
2020-01-13 22:26:12,560-0400 ERROR (tasks/5)
[storage.TaskManager.Task] Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
631, in _loadMetaFile
for line in getProcPool().readLines(filename):
File
"/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py", line
334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
555, in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
543, in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line
448, in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,561-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 90d88529-a051-4acd-bef2-d0aa034c15de
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
1162, in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
751, in _load
self._loadRecoveryMetaFile(taskDir, rn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
705, in _loadRecoveryMetaFile
self._loadMetaFile(taskFile, self.recoveries[n], Recovery.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
653, in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/90d88529-a051-4acd-bef2-d0aa034c15de/90d88529-a051-4acd-bef2-d0aa034c15de.recover.0',)
2020-01-13 22:26:12,607-0400 ERROR (tasks/5) [storage.StoragePool]
Unexpected error (sp:383)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/sp.py", line
378, in startSpm
self.taskMng.recoverDumpedTasks()
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 227, in recoverDumpedTasks
self.queueRecovery(task)
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 48, in queueRecovery
return self._queueTask(task, task.recover)
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 54, in _queueTask
'Task id already in use: {0}'.format(task.id <http://task.id>))
AddTaskError: TaskManager error, unable to add task: ('Task id already
in use: 7df9eeb4-f7a8-4de4-b3f7-5e5607d48dda',)
2020-01-13 22:26:12,608-0400 ERROR (tasks/5) [storage.StoragePool]
failed: TaskManager error, unable to add task: ('Task id already in
use: 7df9eeb4-f7a8-4de4-b3f7-5e5607d48dda',) (sp:384)
2020-01-13 22:26:12,635-0400 ERROR (tasks/5)
[storage.TaskManager.Task]
(Task='3c7de2a0-597c-4ebe-b4de-689dba26045b') Unexpected error (task:875)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
882, in _run
return fn(*args, **kargs)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line
336, in run
return self.cmd(*self.argslist, **self.argsdict)
File "/usr/lib/python2.7/site-packages/vdsm/storage/sp.py", line
378, in startSpm
self.taskMng.recoverDumpedTasks()
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 227, in recoverDumpedTasks
self.queueRecovery(task)
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 48, in queueRecovery
return self._queueTask(task, task.recover)
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 54, in _queueTask
'Task id already in use: {0}'.format(task.id <http://task.id>))
AddTaskError: TaskManager error, unable to add task: ('Task id already
in use: 7df9eeb4-f7a8-4de4-b3f7-5e5607d48dda',)
_______________________________________________
Users mailing list -- users(a)ovirt.org
To unsubscribe send an email to users-leave(a)ovirt.org
Privacy Statement: https://www.ovirt.org/site/privacy-policy/
oVirt Code of Conduct: https://www.ovirt.org/community/about/community-guidelines/
List Archives:
https://lists.ovirt.org/archives/list/users@ovirt.org/message/5XPGERTWVSX...
Met vriendelijke groet, With kind regards,
Jorick Astrego
Netbulae Virtualization Experts
----------------
Tel: 053 20 30 270 info(a)netbulae.eu Staalsteden 4-3A KvK 08198180
Fax: 053 20 30 271 www.netbulae.eu 7547 TA Enschede BTW NL821234584B01
----------------
2:10 p.m.
I seem to have been able to break the loop by manually restarting vdsmd. As
soon as I restarted on one host it was able to be selected as spm.
On Tue, Jan 14, 2020 at 6:21 AM Jorick Astrego <jorick(a)netbulae.eu> wrote:
Hi Jayme,
The only thing I can find related to the vdsm errors you post is
https://bugzilla.redhat.com/show_bug.cgi?id=1493184
Nir states it's just a logging issue so that doesn't help to much.
What version are you running?
Anything in the gluster logs on the node?
Nir Soffer 2018-06-25 12:27:16 UTC
These exceptions:
OSError: [Errno 2] No such file or directory
...
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/e6c5d8a2-5386-11e8-8885-004655214801/mastersd/master/tasks/60bf8af9-d4d3-4753-a40d-2a8d028d3d3c/60bf8af9-d4d3-4753-a40d-2a8d028d3d3c.recover.0',)
Mean that a dumped task could not not loaded because there was no such file in the
task directory.
This error does not effect the SPM start process, the code is trying to load dumped
tasks and ignore the result of the load.
So this looks like log issue, moving severity to low since I don't see any real
issue.
Regarding the exceptions, we have several issues:
1. Logging several exceptions for the same problem - we should log the same issue
exactly once. This happens because the code using the anti-pattern of logging
an exception and raising new one.
2. I'm not sure why we log a traceback for expected error like a missing dumped
task file. This should be logged without a traceback.
3. I'm not sure why missing dumped task is an error, since the SPM code ignore
it. This should be probably a warning.
Regards,
Jorick Astrego
Netbulae
On 1/14/20 3:27 AM, Jayme wrote:
My cluster appears to be experiencing an SPM problem. I recently placed
each host in maintenance to move the ovirt management network to another
interface. All was successful and all VMs are currently running. However,
I'm not facing an SPM contending loop with data center going in and out of
responsive status.
I have a 3 server HCI setup and all volumes are active and healed, there
are no unsynced entries or split brains.
Does anyone know how I could diagnose the SPM issue?
engine.log:
2020-01-13 22:24:54,777-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterTasksListVDSCommand]
(DefaultQuartzScheduler2) [213adf4f] START,
GlusterTasksListVDSCommand(HostName = Orchard0,
VdsIdVDSCommandParametersBase:{hostId='771c67eb-56e6-4736-8c67-668502d4ecf5'}),
log id: 349f80a9
2020-01-13 22:24:55,231-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterTasksListVDSCommand]
(DefaultQuartzScheduler2) [213adf4f] FINISH, GlusterTasksListVDSCommand,
return: [], log id: 349f80a9
2020-01-13 22:24:58,245-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] START,
GlusterServersListVDSCommand(HostName = Orchard0,
VdsIdVDSCommandParametersBase:{hostId='771c67eb-56e6-4736-8c67-668502d4ecf5'}),
log id: 7b04f110
2020-01-13 22:24:58,887-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Command
'org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand'
return value '
TaskStatusListReturn:{status='Status [code=654, message=Not SPM]'}
'
2020-01-13 22:24:58,888-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] HostName = Orchard1
2020-01-13 22:24:58,888-04 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Command
'HSMGetAllTasksStatusesVDSCommand(HostName = Orchard1,
VdsIdVDSCommandParametersBase:{hostId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d'})'
execution failed: IRSGenericException: IRSErrorException:
IRSNonOperationalException: Not SPM
2020-01-13 22:24:59,034-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] FINISH, GlusterServersListVDSCommand,
return: [10.12.0.220/24:CONNECTED, orchard1.grove.silverorange.com:CONNECTED,
orchard2.grove.silverorange.com:DISCONNECTED], log id: 7b04f110
2020-01-13 22:24:59,049-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] START,
GlusterServersListVDSCommand(HostName = Orchard2,
VdsIdVDSCommandParametersBase:{hostId='fd0752d8-2d41-45b0-887a-0ffacbb8a237'}),
log id: 43f1dd82
2020-01-13 22:24:59,099-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] START,
ConnectStoragePoolVDSCommand(HostName = Orchard1,
ConnectStoragePoolVDSCommandParameters:{hostId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d',
vdsId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d',
storagePoolId='a45e442e-9989-11e8-b0e4-00163e4bf18a',
masterVersion='1'}),
log id: 2b397b31
2020-01-13 22:24:59,099-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Executing with
domain map: {edc68a7c-7604-47e6-89bc-3738d727e8fc=active,
23c22a0f-0482-425e-8ada-730cf8ec0751=active,
390c0320-e843-4ff3-a4bb-a9973058447f=active,
fb43d33a-82c8-44cb-8169-090cd0d8f56e=active,
d70b171e-7488-4d52-8cad-bbc581dbf16e=active,
1f2e9989-9ab3-43d5-971d-568b8feca918=active}
2020-01-13 22:24:59,850-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] FINISH, GlusterServersListVDSCommand,
return: [10.12.0.222/24:CONNECTED, 10.11.0.220:CONNECTED,
orchard1.grove.silverorange.com:CONNECTED], log id: 43f1dd82
2020-01-13 22:24:59,852-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] START,
GlusterVolumesListVDSCommand(HostName = Orchard0,
GlusterVolumesListVDSParameters:{hostId='771c67eb-56e6-4736-8c67-668502d4ecf5'}),
log id: 263be6f8
2020-01-13 22:25:00,019-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] FINISH,
ConnectStoragePoolVDSCommand, return: , log id: 2b397b31
2020-01-13 22:25:00,036-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxy]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) []
hostFromVds::selectedVds - 'Orchard1', spmStatus 'Free', storage pool
'Default', storage pool version '4.3'
2020-01-13 22:25:00,056-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxy]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] starting spm on vds
'Orchard1', storage pool 'Default', prevId '-1', LVER
'-1'
2020-01-13 22:25:00,057-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] START,
SpmStartVDSCommand(HostName = Orchard1,
SpmStartVDSCommandParameters:{hostId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d',
storagePoolId='a45e442e-9989-11e8-b0e4-00163e4bf18a', prevId='-1',
prevLVER='-1', storagePoolFormatType='V4',
recoveryMode='Manual',
SCSIFencing='false'}), log id: 3dea111a
2020-01-13 22:25:00,065-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] spmStart polling
started: taskId '671d5904-e062-4d45-9eb4-83a6f13657fe'
2020-01-13 22:25:00,500-04 INFO
[org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand]
(DefaultQuartzScheduler3) [4f66c75b] FINISH, GlusterVolumesListVDSCommand,
return:
{3f8f6a0f-aed4-48e3-9129-18a2a3f64eef=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@743f4102,
71ff56d9-79b8-445d-b637-72ffc974f109=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@cad5f8f4,
752a9438-cd11-426c-b384-bc3c5f86ed07=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@f9f55499,
c3e7447e-8514-4e4a-9ff5-a648fe6aa537=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@7a2c16da,
79e8e93c-57c8-4541-a360-726cec3790cf=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@33e1ab37,
095fd8fc-5322-4741-8805-fc0bb64b554f=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@b28195c0},
log id: 263be6f8
2020-01-13 22:25:03,089-04 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetTaskStatusVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Failed in
'HSMGetTaskStatusVDS' method
2020-01-13 22:25:03,090-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] spmStart polling
ended: taskId '671d5904-e062-4d45-9eb4-83a6f13657fe' task status
'finished'
2020-01-13 22:25:03,090-04 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] Start SPM Task
failed - result: 'cleanSuccess', message: VDSGenericException:
VDSErrorException: Failed to HSMGetTaskStatusVDS, error = TaskManager
error, unable to add task: ('Task id already in use:
7df9eeb4-f7a8-4de4-b3f7-5e5607d48dda',), code = 100
2020-01-13 22:25:03,104-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] spmStart polling
ended, spm status: Free
2020-01-13 22:25:03,105-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] START,
HSMClearTaskVDSCommand(HostName = Orchard1,
HSMTaskGuidBaseVDSCommandParameters:{hostId='fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d',
taskId='671d5904-e062-4d45-9eb4-83a6f13657fe'}), log id: 5335606f
2020-01-13 22:25:03,110-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] FINISH,
HSMClearTaskVDSCommand, return: , log id: 5335606f
2020-01-13 22:25:03,110-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [] FINISH,
SpmStartVDSCommand, return: SpmStatusResult:{SPM Id='-1', SPM LVER='-1',
SPM Status='Free'}, log id: 3dea111a
2020-01-13 22:25:03,117-04 INFO
[org.ovirt.engine.core.bll.storage.pool.SetStoragePoolStatusCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac] Running
command: SetStoragePoolStatusCommand internal: true. Entities affected :
ID: a45e442e-9989-11e8-b0e4-00163e4bf18a Type: StoragePool
2020-01-13 22:25:03,179-04 ERROR
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac]
IrsBroker::Failed::GetStoragePoolInfoVDS: IRSGenericException:
IRSErrorException: SpmStart failed
2020-01-13 22:25:03,205-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxy]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac] Irs placed
on server 'fb1e62d5-1dc1-4ccc-8b2b-cf48f7077d0d' failed. Proceed Failover
2020-01-13 22:25:03,223-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac] START,
ConnectStoragePoolVDSCommand(HostName = Orchard2,
ConnectStoragePoolVDSCommandParameters:{hostId='fd0752d8-2d41-45b0-887a-0ffacbb8a237',
vdsId='fd0752d8-2d41-45b0-887a-0ffacbb8a237',
storagePoolId='a45e442e-9989-11e8-b0e4-00163e4bf18a',
masterVersion='1'}),
log id: 6a7302e9
2020-01-13 22:25:03,224-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-72) [1c8884ac] Executing
with domain map: {edc68a7c-7604-47e6-89bc-3738d727e8fc=active,
23c22a0f-0482-425e-8ada-730cf8ec0751=active,
390c0320-e843-4ff3-a4bb-a9973058447f=active,
fb43d33a-82c8-44cb-8169-090cd0d8f56e=active,
d70b171e-7488-4d52-8cad-bbc581dbf16e=active,
1f2e9989-9ab3-43d5-971d-568b8feca918=active}
-----------------------------
vdsm.log from one of my hosts:
2020-01-13 22:26:12,434-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,435-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 88772af7-8cf5-433e-8be3-8d0adf0bbf04
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 746,
in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 696,
in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs[n], Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/88772af7-8cf5-433e-8be3-8d0adf0bbf04/88772af7-8cf5-433e-8be3-8d0adf0bbf04.job.0',)
2020-01-13 22:26:12,462-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,462-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: a9b11e33-9b93-46a0-a36e-85063fd53ebe
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 751,
in _load
self._loadRecoveryMetaFile(taskDir, rn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 705,
in _loadRecoveryMetaFile
self._loadMetaFile(taskFile, self.recoveries[n], Recovery.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/a9b11e33-9b93-46a0-a36e-85063fd53ebe/a9b11e33-9b93-46a0-a36e-85063fd53ebe.recover.0',)
2020-01-13 22:26:12,476-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,476-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 650f2df4-6489-47e2-af5d-db86a22f01c0
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 751,
in _load
self._loadRecoveryMetaFile(taskDir, rn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 705,
in _loadRecoveryMetaFile
self._loadMetaFile(taskFile, self.recoveries[n], Recovery.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/650f2df4-6489-47e2-af5d-db86a22f01c0/650f2df4-6489-47e2-af5d-db86a22f01c0.recover.0',)
2020-01-13 22:26:12,487-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,488-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: a2e86fcc-8e7e-4e6d-bf5e-5ac61a98169e
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 746,
in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 696,
in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs[n], Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/a2e86fcc-8e7e-4e6d-bf5e-5ac61a98169e/a2e86fcc-8e7e-4e6d-bf5e-5ac61a98169e.job.0',)
2020-01-13 22:26:12,493-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,493-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: eb8b4f7a-9b5c-46f6-aaa7-7ef05dbf1743
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 737,
in _load
self._loadTaskMetaFile(taskDir)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 688,
in _loadTaskMetaFile
self._loadMetaFile(taskFile, self, Task.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/eb8b4f7a-9b5c-46f6-aaa7-7ef05dbf1743/eb8b4f7a-9b5c-46f6-aaa7-7ef05dbf1743.task',)
2020-01-13 22:26:12,505-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,506-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 75318d21-45b2-4dbd-985c-a7851a10a463
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 746,
in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 696,
in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs[n], Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/75318d21-45b2-4dbd-985c-a7851a10a463/75318d21-45b2-4dbd-985c-a7851a10a463.job.0',)
2020-01-13 22:26:12,517-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,517-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 1779b352-022c-49a3-9388-2f688d33cdab
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 746,
in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 696,
in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs[n], Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/1779b352-022c-49a3-9388-2f688d33cdab/1779b352-022c-49a3-9388-2f688d33cdab.job.0',)
2020-01-13 22:26:12,532-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,532-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 0302036a-7d99-4685-befb-6fee1602feaf
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 746,
in _load
self._loadJobMetaFile(taskDir, jn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 696,
in _loadJobMetaFile
self._loadMetaFile(taskFile, self.jobs[n], Job.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/0302036a-7d99-4685-befb-6fee1602feaf/0302036a-7d99-4685-befb-6fee1602feaf.job.0',)
2020-01-13 22:26:12,545-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,546-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 24a825b9-d48d-4134-8aa1-b4db7a9c6ab1
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 737,
in _load
self._loadTaskMetaFile(taskDir)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 688,
in _loadTaskMetaFile
self._loadMetaFile(taskFile, self, Task.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/24a825b9-d48d-4134-8aa1-b4db7a9c6ab1.backup/24a825b9-d48d-4134-8aa1-b4db7a9c6ab1.task',)
2020-01-13 22:26:12,560-0400 ERROR (tasks/5) [storage.TaskManager.Task]
Unexpected error (task:652)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 631,
in _loadMetaFile
for line in getProcPool().readLines(filename):
File "/usr/lib/python2.7/site-packages/vdsm/storage/outOfProcess.py",
line 334, in readLines
return ioproc.readlines(path)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 555,
in readlines
return self.readfile(path, direct).splitlines()
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 543,
in readfile
"direct": direct}, self.timeout)
File "/usr/lib/python2.7/site-packages/ioprocess/__init__.py", line 448,
in _sendCommand
raise OSError(errcode, errstr)
OSError: [Errno 2] No such file or directory
2020-01-13 22:26:12,561-0400 ERROR (tasks/5) [storage.TaskManager]
taskManager: Skipping directory: 90d88529-a051-4acd-bef2-d0aa034c15de
(taskManager:222)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 214, in loadDumpedTasks
t = Task.loadTask(store, taskID)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1162,
in loadTask
t._load(store, ext)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 751,
in _load
self._loadRecoveryMetaFile(taskDir, rn)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 705,
in _loadRecoveryMetaFile
self._loadMetaFile(taskFile, self.recoveries[n], Recovery.fields)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 653,
in _loadMetaFile
raise se.TaskMetaDataLoadError(filename)
TaskMetaDataLoadError: Can't load Task Metadata:
('/rhev/data-center/a45e442e-9989-11e8-b0e4-00163e4bf18a/mastersd/master/tasks/90d88529-a051-4acd-bef2-d0aa034c15de/90d88529-a051-4acd-bef2-d0aa034c15de.recover.0',)
2020-01-13 22:26:12,607-0400 ERROR (tasks/5) [storage.StoragePool]
Unexpected error (sp:383)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/sp.py", line 378, in
startSpm
self.taskMng.recoverDumpedTasks()
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 227, in recoverDumpedTasks
self.queueRecovery(task)
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 48, in queueRecovery
return self._queueTask(task, task.recover)
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 54, in _queueTask
'Task id already in use: {0}'.format(task.id))
AddTaskError: TaskManager error, unable to add task: ('Task id already in
use: 7df9eeb4-f7a8-4de4-b3f7-5e5607d48dda',)
2020-01-13 22:26:12,608-0400 ERROR (tasks/5) [storage.StoragePool] failed:
TaskManager error, unable to add task: ('Task id already in use:
7df9eeb4-f7a8-4de4-b3f7-5e5607d48dda',) (sp:384)
2020-01-13 22:26:12,635-0400 ERROR (tasks/5) [storage.TaskManager.Task]
(Task='3c7de2a0-597c-4ebe-b4de-689dba26045b') Unexpected error (task:875)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 882,
in _run
return fn(*args, **kargs)
File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 336,
in run
return self.cmd(*self.argslist, **self.argsdict)
File "/usr/lib/python2.7/site-packages/vdsm/storage/sp.py", line 378, in
startSpm
self.taskMng.recoverDumpedTasks()
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 227, in recoverDumpedTasks
self.queueRecovery(task)
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 48, in queueRecovery
return self._queueTask(task, task.recover)
File "/usr/lib/python2.7/site-packages/vdsm/storage/taskManager.py",
line 54, in _queueTask
'Task id already in use: {0}'.format(task.id))
AddTaskError: TaskManager error, unable to add task: ('Task id already in
use: 7df9eeb4-f7a8-4de4-b3f7-5e5607d48dda',)
_______________________________________________
Users mailing list -- users(a)ovirt.org
To unsubscribe send an email to users-leave(a)ovirt.org
Privacy Statement: https://www.ovirt.org/site/privacy-policy/
oVirt Code of Conduct: https://www.ovirt.org/community/about/community-guidelines/
List Archives:
https://lists.ovirt.org/archives/list/users@ovirt.org/message/5XPGERTWVSX...
Met vriendelijke groet, With kind regards,
Jorick Astrego
*Netbulae Virtualization Experts *
------------------------------
Tel: 053 20 30 270 info(a)netbulae.eu Staalsteden 4-3A
<https://www.google.com/maps/search/Staalsteden+4-3A?entry=gmail&sourc... KvK
08198180
Fax: 053 20 30 271 www.netbulae.eu 7547 TA Enschede BTW NL821234584B01
------------------------------
_______________________________________________
Users mailing list -- users(a)ovirt.org
To unsubscribe send an email to users-leave(a)ovirt.org
Privacy Statement: https://www.ovirt.org/site/privacy-policy/
oVirt Code of Conduct:
https://www.ovirt.org/community/about/community-guidelines/
List Archives:
https://lists.ovirt.org/archives/list/users@ovirt.org/message/WHX6O2P6273...
1774
days inactive
1774
days old
3 comments
3 participants
participants (3)
-
Eli Mesika -
Jayme -
Jorick Astrego