I'm testing out the managed storage to connect to ceph and I have a few questions: * Would I be correct in assuming that the hosted engine VM needs connectivity to the storage and not just the underlying hosts themselves? It seems like the cinderlib client runs from the engine? * Does the ceph config and keyring need to replicated onto each hypervisor/host? * I have managed to do one block operation so far (i've created a volume which is visible on the ceph side), but multiple other operations have failed and are 'running' in the engine task list. Is there any way I can increase debugging to see whats happening?
On Thu, Jul 4, 2019 at 1:03 PM <dan.poltawski@tnp.net.uk> wrote:
I'm testing out the managed storage to connect to ceph and I have a few questions:
* Would I be correct in assuming that the hosted engine VM needs
connectivity to the storage and not just the underlying hosts themselves? It seems like the cinderlib client runs from the engine?
Yes, this is correct
* Does the ceph config and keyring need to replicated onto each hypervisor/host?
No, see[1], the keyring and ceph config can be present only on the engine machine
* I have managed to do one block operation so far (i've created a volume which is visible on the ceph side), but multiple other operations have failed and are 'running' in the engine task list. Is there any way I can increase debugging to see whats happening?
Can you provide logs? mainly engine.log and cinderlib.log (/var/log/ovirt-engine/cinderlib/cinderlib.log [1] - https://ovirt.org/develop/release-management/features/storage/cinderlib-inte...
Can you provide logs? mainly engine.log and cinderlib.log (/var/log/ovirt-engine/cinderlib/cinderlib.log
If I create two volumes, the first one succeeds successfully, the second one hangs. If I look in the processlist after creating the second volume which doesn't succceed, I see the python ./cinderlib-client.py create_volume [...] command still running. On the ceph side, I can see only the one rbd volume. Logs below: --- cinderlib.log -- 2019-07-04 16:46:30,863 - cinderlib-client - INFO - Fetch backend stats [b07698bb-1688-472f-841b-70a9d52a250d] 2019-07-04 16:46:56,308 - cinderlib-client - INFO - Creating volume '236285cc-ac01-4239-821c-4beadd66923f', with size '2' GB [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] 2019-07-04 16:47:21,671 - cinderlib-client - INFO - Creating volume '84886485-554a-44ca-964c-9758b4a16aae', with size '2' GB [a793bfc9-fc37-4711-a144-d74c100cc75b] --- engine.log --- 2019-07-04 16:46:54,062+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80-ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:46:54,150+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBlockStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:46:56,863+01 INFO [org.ovirt.engine.core.common.utils.cinderlib.CinderlibExecutor] (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] cinderlib output: 2019-07-04 16:46:56,912+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-22) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:00,126+01 INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Command 'AddDisk' id: '15fe157d-7adb-4031-9e81-f51aa0b6528f' child commands '[d056397a-7ed9-4c01-b880-dd518421a2c6]' executions were completed, status 'SUCCEEDED' 2019-07-04 16:47:01,136+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' successfully. 2019-07-04 16:47:01,141+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBlockStorageDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBlockStorageDiskCommand' successfully. 2019-07-04 16:47:01,145+01 WARN [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] VM is null - no unlocking 2019-07-04 16:47:01,186+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:19,446+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80-ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:47:19,464+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBlockStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-2) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'commandCoordinator' is using 1 threads out of 10, 1 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 9 threads waiting for tasks and 0 tasks in queue. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 threads waiting for tasks. 2019-07-04 16:46:54,062+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80-ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:46:54,150+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBlockStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:46:56,863+01 INFO [org.ovirt.engine.core.common.utils.cinderlib.CinderlibExecutor] (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] cinderlib output: 2019-07-04 16:46:56,912+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-22) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:00,126+01 INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Command 'AddDisk' id: '15fe157d-7adb-4031-9e81-f51aa0b6528f' child commands '[d056397a-7ed9-4c01-b880-dd518421a2c6]' executions were completed, status 'SUCCEEDED' 2019-07-04 16:47:01,136+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' successfully. 2019-07-04 16:47:01,141+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBlockStorageDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBlockStorageDiskCommand' successfully. 2019-07-04 16:47:01,145+01 WARN [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] VM is null - no unlocking 2019-07-04 16:47:01,186+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:19,446+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80-ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:47:19,464+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBlockStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-2) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'commandCoordinator' is using 1 threads out of 10, 1 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 9 threads waiting for tasks and 0 tasks in queue. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 threads waiting for tasks.
Hi, Any chance you can setup gdb[1] so we can find out where it's stuck exactly? Also, which version of ovirt are you using? Can you also check the ceph logs for anything suspicious? [1] - https://wiki.python.org/moin/DebuggingWithGdb $ gdb python <cinderlib pid> then `py-bt` On Thu, Jul 4, 2019 at 7:00 PM <dan.poltawski@tnp.net.uk> wrote:
Can you provide logs? mainly engine.log and cinderlib.log (/var/log/ovirt-engine/cinderlib/cinderlib.log
If I create two volumes, the first one succeeds successfully, the second one hangs. If I look in the processlist after creating the second volume which doesn't succceed, I see the python ./cinderlib-client.py create_volume [...] command still running.
On the ceph side, I can see only the one rbd volume.
Logs below:
--- cinderlib.log --
2019-07-04 16:46:30,863 - cinderlib-client - INFO - Fetch backend stats [b07698bb-1688-472f-841b-70a9d52a250d] 2019-07-04 16:46:56,308 - cinderlib-client - INFO - Creating volume '236285cc-ac01-4239-821c-4beadd66923f', with size '2' GB [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] 2019-07-04 16:47:21,671 - cinderlib-client - INFO - Creating volume '84886485-554a-44ca-964c-9758b4a16aae', with size '2' GB [a793bfc9-fc37-4711-a144-d74c100cc75b]
--- engine.log ---
2019-07-04 16:46:54,062+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80-ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:46:54,150+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBlockStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:46:56,863+01 INFO [org.ovirt.engine.core.common.utils.cinderlib.CinderlibExecutor] (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] cinderlib output: 2019-07-04 16:46:56,912+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-22) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:00,126+01 INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Command 'AddDisk' id: '15fe157d-7adb-4031-9e81-f51aa0b6528f' child commands '[d056397a-7ed9-4c01-b880-dd518421a2c6]' executions were completed, status 'SUCCEEDED' 2019-07-04 16:47:01,136+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' successfully. 2019-07-04 16:47:01,141+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBlockStorageDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBlockStorageDiskCommand' successfully. 2019-07-04 16:47:01,145+01 WARN [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] VM is null - no unlocking 2019-07-04 16:47:01,186+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:19,446+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80-ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:47:19,464+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBlockStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-2) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'commandCoordinator' is using 1 threads out of 10, 1 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 9 threads waiting for tasks and 0 tasks in queue. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 threads waiting for tasks.
2019-07-04 16:46:54,062+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80-ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:46:54,150+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBlockStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:46:56,863+01 INFO [org.ovirt.engine.core.common.utils.cinderlib.CinderlibExecutor] (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] cinderlib output: 2019-07-04 16:46:56,912+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-22) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:00,126+01 INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Command 'AddDisk' id: '15fe157d-7adb-4031-9e81-f51aa0b6528f' child commands '[d056397a-7ed9-4c01-b880-dd518421a2c6]' executions were completed, status 'SUCCEEDED' 2019-07-04 16:47:01,136+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' successfully. 2019-07-04 16:47:01,141+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBlockStorageDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBlockStorageDiskCommand' successfully. 2019-07-04 16:47:01,145+01 WARN [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] VM is null - no unlocking 2019-07-04 16:47:01,186+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:19,446+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80-ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:47:19,464+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBlockStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-2) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'commandCoordinator' is using 1 threads out of 10, 1 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 9 threads waiting for tasks and 0 tasks in queue. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 threads waiting for tasks. _______________________________________________ Users mailing list -- users@ovirt.org To unsubscribe send an email to users-leave@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/VW5AZHXGU2YTSB...
Hi, On Sun, 2019-07-07 at 09:31 +0300, Benny Zlotnik wrote:
Any chance you can setup gdb[1] so we can find out where it's stuck exactly?
Yes, abolutely - but I will need some assistance in getting GDB configured in the engine as I am not very familar with it - or how to enable the correct repos to get the debug info. $ gdb python 54654 [...] Reading symbols from /lib64/libfreeblpriv3.so...Reading symbols from /lib64/libfreeblpriv3.so...(no debugging symbols found)...done. (no debugging symbols found)...done. Loaded symbols for /lib64/libfreeblpriv3.so 0x00007fcf82256483 in epoll_wait () from /lib64/libc.so.6 Missing separate debuginfos, use: debuginfo-install python-2.7.5-80.el7_6.x86_64 (gdb) pt-bt Undefined command: "pt-bt". Try "help".
Also, which version of ovirt are you using?
Using 4.3.4
Can you also check the ceph logs for anything suspicious?
I haven't seen anything so far, but is an entirely resonable possibility this is ceph misoconfiguraiton as we are learning about both tools. thanks, Dan
[1] - https://wiki.python.org/moin/DebuggingWithGdb $ gdb python <cinderlib pid> then `py-bt`
On Thu, Jul 4, 2019 at 7:00 PM <dan.poltawski@tnp.net.uk<mailto:dan.poltawski@tnp.net.uk>> wrote:
Can you provide logs? mainly engine.log and cinderlib.log (/var/log/ovirt-engine/cinderlib/cinderlib.log
If I create two volumes, the first one succeeds successfully, the second one hangs. If I look in the processlist after creating the second volume which doesn't succceed, I see the python ./cinderlib- client.py create_volume [...] command still running.
On the ceph side, I can see only the one rbd volume.
Logs below:
--- cinderlib.log --
2019-07-04 16:46:30,863 - cinderlib-client - INFO - Fetch backend stats [b07698bb-1688-472f-841b-70a9d52a250d] 2019-07-04 16:46:56,308 - cinderlib-client - INFO - Creating volume '236285cc-ac01-4239-821c-4beadd66923f', with size '2' GB [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] 2019-07-04 16:47:21,671 - cinderlib-client - INFO - Creating volume '84886485-554a-44ca-964c-9758b4a16aae', with size '2' GB [a793bfc9- fc37-4711-a144-d74c100cc75b]
--- engine.log ---
2019-07-04 16:46:54,062+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80- ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:46:54,150+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator- Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:46:56,863+01 INFO [org.ovirt.engine.core.common.utils.cinderlib.CinderlibExecutor] (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] cinderlib output: 2019-07-04 16:46:56,912+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirect or] (default task-22) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:00,126+01 INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback ] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] Command 'AddDisk' id: '15fe157d-7adb- 4031-9e81-f51aa0b6528f' child commands '[d056397a-7ed9-4c01-b880- dd518421a2c6]' executions were completed, status 'SUCCEEDED' 2019-07-04 16:47:01,136+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f-cb20- 440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' successfully. 2019-07-04 16:47:01,141+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand] (EE-ManagedThreadFactory-engineScheduled- Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand' successfully. 2019-07-04 16:47:01,145+01 WARN [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- ManagedThreadFactory-engineScheduled-Thread-99) [] VM is null - no unlocking 2019-07-04 16:47:01,186+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirect or] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:19,446+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80- ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:47:19,464+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator- Thread-2) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'commandCoordinator' is using 1 threads out of 10, 1 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 9 threads waiting for tasks and 0 tasks in queue. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 threads waiting for tasks.
2019-07-04 16:46:54,062+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80- ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:46:54,150+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator- Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:46:56,863+01 INFO [org.ovirt.engine.core.common.utils.cinderlib.CinderlibExecutor] (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] cinderlib output: 2019-07-04 16:46:56,912+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirect or] (default task-22) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:00,126+01 INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback ] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] Command 'AddDisk' id: '15fe157d-7adb- 4031-9e81-f51aa0b6528f' child commands '[d056397a-7ed9-4c01-b880- dd518421a2c6]' executions were completed, status 'SUCCEEDED' 2019-07-04 16:47:01,136+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f-cb20- 440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' successfully. 2019-07-04 16:47:01,141+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand] (EE-ManagedThreadFactory-engineScheduled- Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand' successfully. 2019-07-04 16:47:01,145+01 WARN [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- ManagedThreadFactory-engineScheduled-Thread-99) [] VM is null - no unlocking 2019-07-04 16:47:01,186+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirect or] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:19,446+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80- ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:47:19,464+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator- Thread-2) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'commandCoordinator' is using 1 threads out of 10, 1 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 9 threads waiting for tasks and 0 tasks in queue. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 threads waiting for tasks. _______________________________________________ Users mailing list -- users@ovirt.org<mailto:users@ovirt.org> To unsubscribe send an email to users-leave@ovirt.org<mailto:users-leave@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/VW5AZHXGU2YTSB...
________________________________ The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England & Wales with company number: 07667393 This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e-mail if you have received this e-mail by mistake and delete this e-mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
Hi, You have a typo, it's py-bt and I just tried it myself, I only had to install: $ yum install -y python-devel (in addition to the packages specified in the link) On Mon, Jul 8, 2019 at 2:40 PM Dan Poltawski <dan.poltawski@tnp.net.uk> wrote:
Hi,
On Sun, 2019-07-07 at 09:31 +0300, Benny Zlotnik wrote:
Any chance you can setup gdb[1] so we can find out where it's stuck exactly?
Yes, abolutely - but I will need some assistance in getting GDB configured in the engine as I am not very familar with it - or how to enable the correct repos to get the debug info.
$ gdb python 54654
[...]
Reading symbols from /lib64/libfreeblpriv3.so...Reading symbols from /lib64/libfreeblpriv3.so...(no debugging symbols found)...done. (no debugging symbols found)...done. Loaded symbols for /lib64/libfreeblpriv3.so 0x00007fcf82256483 in epoll_wait () from /lib64/libc.so.6 Missing separate debuginfos, use: debuginfo-install python-2.7.5-80.el7_6.x86_64 (gdb) pt-bt Undefined command: "pt-bt". Try "help".
Also, which version of ovirt are you using?
Using 4.3.4
Can you also check the ceph logs for anything suspicious?
I haven't seen anything so far, but is an entirely resonable possibility this is ceph misoconfiguraiton as we are learning about both tools.
thanks,
Dan
[1] - https://wiki.python.org/moin/DebuggingWithGdb $ gdb python <cinderlib pid> then `py-bt`
On Thu, Jul 4, 2019 at 7:00 PM <dan.poltawski@tnp.net.uk> wrote:
Can you provide logs? mainly engine.log and cinderlib.log (/var/log/ovirt-engine/cinderlib/cinderlib.log
If I create two volumes, the first one succeeds successfully, the second one hangs. If I look in the processlist after creating the second volume which doesn't succceed, I see the python ./cinderlib- client.py create_volume [...] command still running.
On the ceph side, I can see only the one rbd volume.
Logs below:
--- cinderlib.log --
2019-07-04 16:46:30,863 - cinderlib-client - INFO - Fetch backend stats [b07698bb-1688-472f-841b-70a9d52a250d] 2019-07-04 16:46:56,308 - cinderlib-client - INFO - Creating volume '236285cc-ac01-4239-821c-4beadd66923f', with size '2' GB [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] 2019-07-04 16:47:21,671 - cinderlib-client - INFO - Creating volume '84886485-554a-44ca-964c-9758b4a16aae', with size '2' GB [a793bfc9- fc37-4711-a144-d74c100cc75b]
--- engine.log ---
2019-07-04 16:46:54,062+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80- ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:46:54,150+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator- Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:46:56,863+01 INFO [org.ovirt.engine.core.common.utils.cinderlib.CinderlibExecutor] (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] cinderlib output: 2019-07-04 16:46:56,912+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirect or] (default task-22) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:00,126+01 INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback ] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] Command 'AddDisk' id: '15fe157d-7adb- 4031-9e81-f51aa0b6528f' child commands '[d056397a-7ed9-4c01-b880- dd518421a2c6]' executions were completed, status 'SUCCEEDED' 2019-07-04 16:47:01,136+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f-cb20- 440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' successfully. 2019-07-04 16:47:01,141+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand] (EE-ManagedThreadFactory-engineScheduled- Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand' successfully. 2019-07-04 16:47:01,145+01 WARN [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- ManagedThreadFactory-engineScheduled-Thread-99) [] VM is null - no unlocking 2019-07-04 16:47:01,186+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirect or] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:19,446+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80- ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:47:19,464+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator- Thread-2) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'commandCoordinator' is using 1 threads out of 10, 1 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 9 threads waiting for tasks and 0 tasks in queue. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 threads waiting for tasks.
2019-07-04 16:46:54,062+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80- ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:46:54,150+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator- Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:46:56,863+01 INFO [org.ovirt.engine.core.common.utils.cinderlib.CinderlibExecutor] (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] cinderlib output: 2019-07-04 16:46:56,912+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirect or] (default task-22) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:00,126+01 INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback ] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] Command 'AddDisk' id: '15fe157d-7adb- 4031-9e81-f51aa0b6528f' child commands '[d056397a-7ed9-4c01-b880- dd518421a2c6]' executions were completed, status 'SUCCEEDED' 2019-07-04 16:47:01,136+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f-cb20- 440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' successfully. 2019-07-04 16:47:01,141+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand] (EE-ManagedThreadFactory-engineScheduled- Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand' successfully. 2019-07-04 16:47:01,145+01 WARN [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- ManagedThreadFactory-engineScheduled-Thread-99) [] VM is null - no unlocking 2019-07-04 16:47:01,186+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirect or] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:19,446+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80- ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:47:19,464+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator- Thread-2) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'commandCoordinator' is using 1 threads out of 10, 1 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 9 threads waiting for tasks and 0 tasks in queue. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 threads waiting for tasks. _______________________________________________ Users mailing list -- users@ovirt.org To unsubscribe send an email to users-leave@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/VW5AZHXGU2YTSB...
------------------------------
The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England & Wales with company number: 07667393
This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e-mail if you have received this e-mail by mistake and delete this e-mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
On Mon, 2019-07-08 at 16:25 +0300, Benny Zlotnik wrote:
Hi,
You have a typo, it's py-bt and I just tried it myself, I only had to install: $ yum install -y python-devel (in addition to the packages specified in the link)
Thanks - this is what I get: #3 Frame 0x7f2046b59ad0, for file /usr/lib/python2.7/site- packages/eventlet/hubs/epolls.py, line 62, in do_poll (self=<Hub(next_timers=[], clock=<function at remote 0x7f20661059b0>, debug_exceptions=True, debug_blocking_resolution=1, modify=<built-in method modify of select.epoll object at remote 0x7f2048455168>, running=True, debug_blocking=False, listeners={'read': {20: <FdListener(fileno=20, cb=<built-in method switch of greenlet.greenlet object at remote 0x7f2046878410>, spent=False, greenlet=<greenlet.greenlet at remote 0x7f2046878410>, evtype='read', mark_as_closed=<instancemethod at remote 0x7f2046b09500>, tb=<built-in method throw of greenlet.greenlet object at remote 0x7f2046878410>) at remote 0x7f20468cda10>}, 'write': {}}, timers_canceled=0, greenlet=<greenlet.greenlet at remote 0x7f2046af70f0>, closed=[], stopping=False, timers=[(<float at remote 0x2830e20>, <Timer(seconds=<float at remote 0xced610>, tpl=(<built-in method switch of greenlet.greenlet object at remote 0x7f2046934c30>, (), {}), called=F...(truncated) return self.poll.poll(seconds) #6 Frame 0x32fbf30, for file /usr/lib/python2.7/site- packages/eventlet/hubs/poll.py, line 85, in wait (self=<Hub(next_timers=[], clock=<function at remote 0x7f20661059b0>, debug_exceptions=True, debug_blocking_resolution=1, modify=<built-in method modify of select.epoll object at remote 0x7f2048455168>, running=True, debug_blocking=False, listeners={'read': {20: <FdListener(fileno=20, cb=<built-in method switch of greenlet.greenlet object at remote 0x7f2046878410>, spent=False, greenlet=<greenlet.greenlet at remote 0x7f2046878410>, evtype='read', mark_as_closed=<instancemethod at remote 0x7f2046b09500>, tb=<built-in method throw of greenlet.greenlet object at remote 0x7f2046878410>) at remote 0x7f20468cda10>}, 'write': {}}, timers_canceled=0, greenlet=<greenlet.greenlet at remote 0x7f2046af70f0>, closed=[], stopping=False, timers=[(<float at remote 0x2830e20>, <Timer(seconds=<float at remote 0xced610>, tpl=(<built-in method switch of greenlet.greenlet object at remote 0x7f2046934c30>, (), {}), called=False) at r...(truncated) presult = self.do_poll(seconds) #10 Frame 0x7f2046afca00, for file /usr/lib/python2.7/site- packages/eventlet/hubs/hub.py, line 346, in run (self=<Hub(next_timers=[], clock=<function at remote 0x7f20661059b0>, debug_exceptions=True, debug_blocking_resolution=1, modify=<built-in method modify of select.epoll object at remote 0x7f2048455168>, running=True, debug_blocking=False, listeners={'read': {20: <FdListener(fileno=20, cb=<built-in method switch of greenlet.greenlet object at remote 0x7f2046878410>, spent=False, greenlet=<greenlet.greenlet at remote 0x7f2046878410>, evtype='read', mark_as_closed=<instancemethod at remote 0x7f2046b09500>, tb=<built-in method throw of greenlet.greenlet object at remote 0x7f2046878410>) at remote 0x7f20468cda10>}, 'write': {}}, timers_canceled=0, greenlet=<greenlet.greenlet at remote 0x7f2046af70f0>, closed=[], stopping=False, timers=[(<float at remote 0x2830e20>, <Timer(seconds=<float at remote 0xced610>, tpl=(<built-in method switch of greenlet.greenlet object at remote 0x7f2046934c30>, (), {}), called=False) ...(truncated) self.wait(sleep_time)
On Mon, Jul 8, 2019 at 2:40 PM Dan Poltawski < dan.poltawski@tnp.net.uk> wrote:
Hi,
On Sun, 2019-07-07 at 09:31 +0300, Benny Zlotnik wrote:
Any chance you can setup gdb[1] so we can find out where it's stuck exactly?
Yes, abolutely - but I will need some assistance in getting GDB configured in the engine as I am not very familar with it - or how to enable the correct repos to get the debug info.
$ gdb python 54654
[...]
Reading symbols from /lib64/libfreeblpriv3.so...Reading symbols from /lib64/libfreeblpriv3.so...(no debugging symbols found)...done. (no debugging symbols found)...done. Loaded symbols for /lib64/libfreeblpriv3.so 0x00007fcf82256483 in epoll_wait () from /lib64/libc.so.6 Missing separate debuginfos, use: debuginfo-install python-2.7.5- 80.el7_6.x86_64 (gdb) pt-bt Undefined command: "pt-bt". Try "help".
Also, which version of ovirt are you using?
Using 4.3.4
Can you also check the ceph logs for anything suspicious?
I haven't seen anything so far, but is an entirely resonable possibility this is ceph misoconfiguraiton as we are learning about both tools.
thanks,
Dan
[1] - https://wiki.python.org/moin/DebuggingWithGdb $ gdb python <cinderlib pid> then `py-bt`
On Thu, Jul 4, 2019 at 7:00 PM <dan.poltawski@tnp.net.uk>
wrote:
> Can you provide logs? mainly engine.log and cinderlib.log > (/var/log/ovirt-engine/cinderlib/cinderlib.log
If I create two volumes, the first one succeeds successfully, the second one hangs. If I look in the processlist after creating the second volume which doesn't succceed, I see the python ./cinderlib- client.py create_volume [...] command still running.
On the ceph side, I can see only the one rbd volume.
Logs below:
--- cinderlib.log --
2019-07-04 16:46:30,863 - cinderlib-client - INFO - Fetch backend stats [b07698bb-1688-472f-841b-70a9d52a250d] 2019-07-04 16:46:56,308 - cinderlib-client - INFO - Creating volume '236285cc-ac01-4239-821c-4beadd66923f', with size '2' GB [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] 2019-07-04 16:47:21,671 - cinderlib-client - INFO - Creating volume '84886485-554a-44ca-964c-9758b4a16aae', with size '2' GB [a793bfc9- fc37-4711-a144-d74c100cc75b]
--- engine.log ---
2019-07-04 16:46:54,062+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80- ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:46:54,150+01 INFO
[org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged Bloc
kStorageDiskCommand] (EE-ManagedThreadFactory- commandCoordinator- Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:46:56,863+01 INFO
[org.ovirt.engine.core.common.utils.cinderlib.CinderlibExecutor ]
(EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] cinderlib output: 2019-07-04 16:46:56,912+01 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDi rect
or] (default task-22) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:00,126+01 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCall back
] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] Command 'AddDisk' id: '15fe157d-7adb- 4031-9e81-f51aa0b6528f' child commands '[d056397a-7ed9- 4c01-b880- dd518421a2c6]' executions were completed, status 'SUCCEEDED' 2019-07-04 16:47:01,136+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f- cb20- 440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' successfully. 2019-07-04 16:47:01,141+01 INFO
[org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged Bloc
kStorageDiskCommand] (EE-ManagedThreadFactory- engineScheduled- Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command
'org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged Bloc
kStorageDiskCommand' successfully. 2019-07-04 16:47:01,145+01 WARN [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- ManagedThreadFactory-engineScheduled-Thread-99) [] VM is null - no unlocking 2019-07-04 16:47:01,186+01 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDi rect
or] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:19,446+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80- ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:47:19,464+01 INFO
[org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged Bloc
kStorageDiskCommand] (EE-ManagedThreadFactory- commandCoordinator- Thread-2) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:48:19,501+01 INFO
ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'commandCoordinator' is using 1 threads out of 10, 1
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- threads
waiting for tasks. 2019-07-04 16:48:19,501+01 INFO
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-
ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-
ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 9 threads waiting for tasks and 0 tasks in queue. 2019-07-04 16:48:19,501+01 INFO
ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- threads
waiting for tasks. 2019-07-04 16:48:19,501+01 INFO
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-
ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO
ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'hostUpdatesChecker' is using 0 threads out of 5, 1
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- threads
waiting for tasks.
2019-07-04 16:46:54,062+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80- ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:46:54,150+01 INFO
[org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged Bloc
kStorageDiskCommand] (EE-ManagedThreadFactory- commandCoordinator- Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:46:56,863+01 INFO
[org.ovirt.engine.core.common.utils.cinderlib.CinderlibExecutor ]
(EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] cinderlib output: 2019-07-04 16:46:56,912+01 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDi rect
or] (default task-22) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:00,126+01 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCall back
] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] Command 'AddDisk' id: '15fe157d-7adb- 4031-9e81-f51aa0b6528f' child commands '[d056397a-7ed9- 4c01-b880- dd518421a2c6]' executions were completed, status 'SUCCEEDED' 2019-07-04 16:47:01,136+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f- cb20- 440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' successfully. 2019-07-04 16:47:01,141+01 INFO
[org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged Bloc
kStorageDiskCommand] (EE-ManagedThreadFactory- engineScheduled- Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command
'org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged Bloc
kStorageDiskCommand' successfully. 2019-07-04 16:47:01,145+01 WARN [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- ManagedThreadFactory-engineScheduled-Thread-99) [] VM is null - no unlocking 2019-07-04 16:47:01,186+01 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDi rect
or] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:19,446+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80- ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:47:19,464+01 INFO
[org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged Bloc
kStorageDiskCommand] (EE-ManagedThreadFactory- commandCoordinator- Thread-2) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:48:19,501+01 INFO
ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'commandCoordinator' is using 1 threads out of 10, 1
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- threads
waiting for tasks. 2019-07-04 16:48:19,501+01 INFO
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-
ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-
ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 9 threads waiting for tasks and 0 tasks in queue. 2019-07-04 16:48:19,501+01 INFO
ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- threads
waiting for tasks. 2019-07-04 16:48:19,501+01 INFO
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-
ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO
ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'hostUpdatesChecker' is using 0 threads out of 5, 1
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- threads
waiting for tasks. _______________________________________________ Users mailing list -- users@ovirt.org To unsubscribe send an email to users-leave@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/VW5AZHXGU2YTSB...
The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England & Wales with company number: 07667393 This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e-mail if you have received this e-mail by mistake and delete this e-mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
________________________________ The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England & Wales with company number: 07667393 This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e-mail if you have received this e-mail by mistake and delete this e-mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
Not too useful unfortunately :\ Can you try py-list instead of py-bt? Perhaps it will provide better results On Mon, Jul 8, 2019 at 4:41 PM Dan Poltawski <dan.poltawski@tnp.net.uk> wrote:
On Mon, 2019-07-08 at 16:25 +0300, Benny Zlotnik wrote:
Hi,
You have a typo, it's py-bt and I just tried it myself, I only had to install: $ yum install -y python-devel (in addition to the packages specified in the link)
Thanks - this is what I get:
#3 Frame 0x7f2046b59ad0, for file /usr/lib/python2.7/site- packages/eventlet/hubs/epolls.py, line 62, in do_poll (self=<Hub(next_timers=[], clock=<function at remote 0x7f20661059b0>, debug_exceptions=True, debug_blocking_resolution=1, modify=<built-in method modify of select.epoll object at remote 0x7f2048455168>, running=True, debug_blocking=False, listeners={'read': {20: <FdListener(fileno=20, cb=<built-in method switch of greenlet.greenlet object at remote 0x7f2046878410>, spent=False, greenlet=<greenlet.greenlet at remote 0x7f2046878410>, evtype='read', mark_as_closed=<instancemethod at remote 0x7f2046b09500>, tb=<built-in method throw of greenlet.greenlet object at remote 0x7f2046878410>) at remote 0x7f20468cda10>}, 'write': {}}, timers_canceled=0, greenlet=<greenlet.greenlet at remote 0x7f2046af70f0>, closed=[], stopping=False, timers=[(<float at remote 0x2830e20>, <Timer(seconds=<float at remote 0xced610>, tpl=(<built-in method switch of greenlet.greenlet object at remote 0x7f2046934c30>, (), {}), called=F...(truncated) return self.poll.poll(seconds) #6 Frame 0x32fbf30, for file /usr/lib/python2.7/site- packages/eventlet/hubs/poll.py, line 85, in wait (self=<Hub(next_timers=[], clock=<function at remote 0x7f20661059b0>, debug_exceptions=True, debug_blocking_resolution=1, modify=<built-in method modify of select.epoll object at remote 0x7f2048455168>, running=True, debug_blocking=False, listeners={'read': {20: <FdListener(fileno=20, cb=<built-in method switch of greenlet.greenlet object at remote 0x7f2046878410>, spent=False, greenlet=<greenlet.greenlet at remote 0x7f2046878410>, evtype='read', mark_as_closed=<instancemethod at remote 0x7f2046b09500>, tb=<built-in method throw of greenlet.greenlet object at remote 0x7f2046878410>) at remote 0x7f20468cda10>}, 'write': {}}, timers_canceled=0, greenlet=<greenlet.greenlet at remote 0x7f2046af70f0>, closed=[], stopping=False, timers=[(<float at remote 0x2830e20>, <Timer(seconds=<float at remote 0xced610>, tpl=(<built-in method switch of greenlet.greenlet object at remote 0x7f2046934c30>, (), {}), called=False) at r...(truncated) presult = self.do_poll(seconds) #10 Frame 0x7f2046afca00, for file /usr/lib/python2.7/site- packages/eventlet/hubs/hub.py, line 346, in run (self=<Hub(next_timers=[], clock=<function at remote 0x7f20661059b0>, debug_exceptions=True, debug_blocking_resolution=1, modify=<built-in method modify of select.epoll object at remote 0x7f2048455168>, running=True, debug_blocking=False, listeners={'read': {20: <FdListener(fileno=20, cb=<built-in method switch of greenlet.greenlet object at remote 0x7f2046878410>, spent=False, greenlet=<greenlet.greenlet at remote 0x7f2046878410>, evtype='read', mark_as_closed=<instancemethod at remote 0x7f2046b09500>, tb=<built-in method throw of greenlet.greenlet object at remote 0x7f2046878410>) at remote 0x7f20468cda10>}, 'write': {}}, timers_canceled=0, greenlet=<greenlet.greenlet at remote 0x7f2046af70f0>, closed=[], stopping=False, timers=[(<float at remote 0x2830e20>, <Timer(seconds=<float at remote 0xced610>, tpl=(<built-in method switch of greenlet.greenlet object at remote 0x7f2046934c30>, (), {}), called=False) ...(truncated) self.wait(sleep_time)
On Mon, Jul 8, 2019 at 2:40 PM Dan Poltawski < dan.poltawski@tnp.net.uk> wrote:
Hi,
On Sun, 2019-07-07 at 09:31 +0300, Benny Zlotnik wrote:
Any chance you can setup gdb[1] so we can find out where it's stuck exactly?
Yes, abolutely - but I will need some assistance in getting GDB configured in the engine as I am not very familar with it - or how to enable the correct repos to get the debug info.
$ gdb python 54654
[...]
Reading symbols from /lib64/libfreeblpriv3.so...Reading symbols from /lib64/libfreeblpriv3.so...(no debugging symbols found)...done. (no debugging symbols found)...done. Loaded symbols for /lib64/libfreeblpriv3.so 0x00007fcf82256483 in epoll_wait () from /lib64/libc.so.6 Missing separate debuginfos, use: debuginfo-install python-2.7.5- 80.el7_6.x86_64 (gdb) pt-bt Undefined command: "pt-bt". Try "help".
Also, which version of ovirt are you using?
Using 4.3.4
Can you also check the ceph logs for anything suspicious?
I haven't seen anything so far, but is an entirely resonable possibility this is ceph misoconfiguraiton as we are learning about both tools.
thanks,
Dan
[1] - https://wiki.python.org/moin/DebuggingWithGdb $ gdb python <cinderlib pid> then `py-bt`
On Thu, Jul 4, 2019 at 7:00 PM <dan.poltawski@tnp.net.uk>
wrote:
> > Can you provide logs? mainly engine.log and cinderlib.log > > (/var/log/ovirt-engine/cinderlib/cinderlib.log > > > If I create two volumes, the first one succeeds successfully, the > second one hangs. If I look in the processlist after creating the > second volume which doesn't succceed, I see the python ./cinderlib- > client.py create_volume [...] command still running. > > On the ceph side, I can see only the one rbd volume. > > Logs below: > > > > --- cinderlib.log -- > > 2019-07-04 16:46:30,863 - cinderlib-client - INFO - Fetch backend > stats [b07698bb-1688-472f-841b-70a9d52a250d] > 2019-07-04 16:46:56,308 - cinderlib-client - INFO - Creating volume > '236285cc-ac01-4239-821c-4beadd66923f', with size '2' GB [0b0f0d6f- > cb20-440a-bacb-7f5ead2b4b4d] > 2019-07-04 16:47:21,671 - cinderlib-client - INFO - Creating volume > '84886485-554a-44ca-964c-9758b4a16aae', with size '2' GB [a793bfc9- > fc37-4711-a144-d74c100cc75b] > > --- engine.log --- > > 2019-07-04 16:46:54,062+01 INFO > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default > task-22) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: > AddDiskCommand internal: false. Entities affected : ID: 31536d80- > ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK > with role type USER > 2019-07-04 16:46:54,150+01 INFO > [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged Bloc > kStorageDiskCommand] (EE-ManagedThreadFactory- commandCoordinator- > Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: > AddManagedBlockStorageDiskCommand internal: true. > 2019-07-04 16:46:56,863+01 INFO > [org.ovirt.engine.core.common.utils.cinderlib.CinderlibExecutor ] > (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f- > cb20-440a-bacb-7f5ead2b4b4d] cinderlib output: > 2019-07-04 16:46:56,912+01 INFO > [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDi rect > or] (default task-22) [] EVENT_ID: > USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was > successfully added. > 2019-07-04 16:47:00,126+01 INFO > [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCall back > ] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [0b0f0d6f- > cb20-440a-bacb-7f5ead2b4b4d] Command 'AddDisk' id: '15fe157d-7adb- > 4031-9e81-f51aa0b6528f' child commands '[d056397a-7ed9- 4c01-b880- > dd518421a2c6]' executions were completed, status 'SUCCEEDED' > 2019-07-04 16:47:01,136+01 INFO > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- > ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f- cb20- > 440a-bacb-7f5ead2b4b4d] Ending command > 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' > successfully. > 2019-07-04 16:47:01,141+01 INFO > [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged Bloc > kStorageDiskCommand] (EE-ManagedThreadFactory- engineScheduled- > Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command > 'org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged Bloc > kStorageDiskCommand' successfully. > 2019-07-04 16:47:01,145+01 WARN > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- > ManagedThreadFactory-engineScheduled-Thread-99) [] VM is null - no > unlocking > 2019-07-04 16:47:01,186+01 INFO > [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDi rect > or] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] > EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' > was successfully added. > 2019-07-04 16:47:19,446+01 INFO > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default > task-22) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: > AddDiskCommand internal: false. Entities affected : ID: 31536d80- > ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK > with role type USER > 2019-07-04 16:47:19,464+01 INFO > [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged Bloc > kStorageDiskCommand] (EE-ManagedThreadFactory- commandCoordinator- > Thread-2) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: > AddManagedBlockStorageDiskCommand internal: true. > 2019-07-04 16:48:19,501+01 INFO > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > pool 'commandCoordinator' is using 1 threads out of 10, 1 threads > waiting for tasks. > 2019-07-04 16:48:19,501+01 INFO > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > pool 'default' is using 0 threads out of 1, 5 threads waiting for > tasks. > 2019-07-04 16:48:19,501+01 INFO > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > pool 'engine' is using 0 threads out of 500, 9 threads waiting for > tasks and 0 tasks in queue. > 2019-07-04 16:48:19,501+01 INFO > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > pool 'engineScheduled' is using 0 threads out of 100, 100 threads > waiting for tasks. > 2019-07-04 16:48:19,501+01 INFO > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 > threads waiting for tasks. > 2019-07-04 16:48:19,501+01 INFO > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 threads > waiting for tasks. > > > > 2019-07-04 16:46:54,062+01 INFO > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default > task-22) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: > AddDiskCommand internal: false. Entities affected : ID: 31536d80- > ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK > with role type USER > 2019-07-04 16:46:54,150+01 INFO > [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged Bloc > kStorageDiskCommand] (EE-ManagedThreadFactory- commandCoordinator- > Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: > AddManagedBlockStorageDiskCommand internal: true. > 2019-07-04 16:46:56,863+01 INFO > [org.ovirt.engine.core.common.utils.cinderlib.CinderlibExecutor ] > (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f- > cb20-440a-bacb-7f5ead2b4b4d] cinderlib output: > 2019-07-04 16:46:56,912+01 INFO > [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDi rect > or] (default task-22) [] EVENT_ID: > USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was > successfully added. > 2019-07-04 16:47:00,126+01 INFO > [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCall back > ] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [0b0f0d6f- > cb20-440a-bacb-7f5ead2b4b4d] Command 'AddDisk' id: '15fe157d-7adb- > 4031-9e81-f51aa0b6528f' child commands '[d056397a-7ed9- 4c01-b880- > dd518421a2c6]' executions were completed, status 'SUCCEEDED' > 2019-07-04 16:47:01,136+01 INFO > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- > ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f- cb20- > 440a-bacb-7f5ead2b4b4d] Ending command > 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' > successfully. > 2019-07-04 16:47:01,141+01 INFO > [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged Bloc > kStorageDiskCommand] (EE-ManagedThreadFactory- engineScheduled- > Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command > 'org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged Bloc > kStorageDiskCommand' successfully. > 2019-07-04 16:47:01,145+01 WARN > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- > ManagedThreadFactory-engineScheduled-Thread-99) [] VM is null - no > unlocking > 2019-07-04 16:47:01,186+01 INFO > [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDi rect > or] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] > EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' > was successfully added. > 2019-07-04 16:47:19,446+01 INFO > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default > task-22) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: > AddDiskCommand internal: false. Entities affected : ID: 31536d80- > ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK > with role type USER > 2019-07-04 16:47:19,464+01 INFO > [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged Bloc > kStorageDiskCommand] (EE-ManagedThreadFactory- commandCoordinator- > Thread-2) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: > AddManagedBlockStorageDiskCommand internal: true. > 2019-07-04 16:48:19,501+01 INFO > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > pool 'commandCoordinator' is using 1 threads out of 10, 1 threads > waiting for tasks. > 2019-07-04 16:48:19,501+01 INFO > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > pool 'default' is using 0 threads out of 1, 5 threads waiting for > tasks. > 2019-07-04 16:48:19,501+01 INFO > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > pool 'engine' is using 0 threads out of 500, 9 threads waiting for > tasks and 0 tasks in queue. > 2019-07-04 16:48:19,501+01 INFO > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > pool 'engineScheduled' is using 0 threads out of 100, 100 threads > waiting for tasks. > 2019-07-04 16:48:19,501+01 INFO > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 > threads waiting for tasks. > 2019-07-04 16:48:19,501+01 INFO > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 threads > waiting for tasks. > _______________________________________________ > Users mailing list -- users@ovirt.org > To unsubscribe send an email to users-leave@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/VW5AZHXGU2YTSB...
The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England & Wales with company number: 07667393 This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e-mail if you have received this e-mail by mistake and delete this e-mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
________________________________
The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England & Wales with company number: 07667393
This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e-mail if you have received this e-mail by mistake and delete this e-mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
On Mon, 2019-07-08 at 16:49 +0300, Benny Zlotnik wrote:
Not too useful unfortunately :\ Can you try py-list instead of py-bt? Perhaps it will provide better results
(gdb) py-list 57 if get_errno(ex) != errno.EEXIST: 58 raise 59 return listener 60 61 def do_poll(self, seconds):
62 return self.poll.poll(seconds)
Thanks for you help, Dan
On Mon, Jul 8, 2019 at 4:41 PM Dan Poltawski < dan.poltawski@tnp.net.uk> wrote:
On Mon, 2019-07-08 at 16:25 +0300, Benny Zlotnik wrote:
Hi,
You have a typo, it's py-bt and I just tried it myself, I only had to install: $ yum install -y python-devel (in addition to the packages specified in the link)
Thanks - this is what I get:
#3 Frame 0x7f2046b59ad0, for file /usr/lib/python2.7/site- packages/eventlet/hubs/epolls.py, line 62, in do_poll (self=<Hub(next_timers=[], clock=<function at remote 0x7f20661059b0>, debug_exceptions=True, debug_blocking_resolution=1, modify=<built- in method modify of select.epoll object at remote 0x7f2048455168>, running=True, debug_blocking=False, listeners={'read': {20: <FdListener(fileno=20, cb=<built-in method switch of greenlet.greenlet object at remote 0x7f2046878410>, spent=False, greenlet=<greenlet.greenlet at remote 0x7f2046878410>, evtype='read', mark_as_closed=<instancemethod at remote 0x7f2046b09500>, tb=<built-in method throw of greenlet.greenlet object at remote 0x7f2046878410>) at remote 0x7f20468cda10>}, 'write': {}}, timers_canceled=0, greenlet=<greenlet.greenlet at remote 0x7f2046af70f0>, closed=[], stopping=False, timers=[(<float at remote 0x2830e20>, <Timer(seconds=<float at remote 0xced610>, tpl=(<built-in method switch of greenlet.greenlet object at remote 0x7f2046934c30>, (), {}), called=F...(truncated) return self.poll.poll(seconds) #6 Frame 0x32fbf30, for file /usr/lib/python2.7/site- packages/eventlet/hubs/poll.py, line 85, in wait (self=<Hub(next_timers=[], clock=<function at remote 0x7f20661059b0>, debug_exceptions=True, debug_blocking_resolution=1, modify=<built- in method modify of select.epoll object at remote 0x7f2048455168>, running=True, debug_blocking=False, listeners={'read': {20: <FdListener(fileno=20, cb=<built-in method switch of greenlet.greenlet object at remote 0x7f2046878410>, spent=False, greenlet=<greenlet.greenlet at remote 0x7f2046878410>, evtype='read', mark_as_closed=<instancemethod at remote 0x7f2046b09500>, tb=<built-in method throw of greenlet.greenlet object at remote 0x7f2046878410>) at remote 0x7f20468cda10>}, 'write': {}}, timers_canceled=0, greenlet=<greenlet.greenlet at remote 0x7f2046af70f0>, closed=[], stopping=False, timers=[(<float at remote 0x2830e20>, <Timer(seconds=<float at remote 0xced610>, tpl=(<built-in method switch of greenlet.greenlet object at remote 0x7f2046934c30>, (), {}), called=False) at r...(truncated) presult = self.do_poll(seconds) #10 Frame 0x7f2046afca00, for file /usr/lib/python2.7/site- packages/eventlet/hubs/hub.py, line 346, in run (self=<Hub(next_timers=[], clock=<function at remote 0x7f20661059b0>, debug_exceptions=True, debug_blocking_resolution=1, modify=<built- in method modify of select.epoll object at remote 0x7f2048455168>, running=True, debug_blocking=False, listeners={'read': {20: <FdListener(fileno=20, cb=<built-in method switch of greenlet.greenlet object at remote 0x7f2046878410>, spent=False, greenlet=<greenlet.greenlet at remote 0x7f2046878410>, evtype='read', mark_as_closed=<instancemethod at remote 0x7f2046b09500>, tb=<built-in method throw of greenlet.greenlet object at remote 0x7f2046878410>) at remote 0x7f20468cda10>}, 'write': {}}, timers_canceled=0, greenlet=<greenlet.greenlet at remote 0x7f2046af70f0>, closed=[], stopping=False, timers=[(<float at remote 0x2830e20>, <Timer(seconds=<float at remote 0xced610>, tpl=(<built-in method switch of greenlet.greenlet object at remote 0x7f2046934c30>, (), {}), called=False) ...(truncated) self.wait(sleep_time)
On Mon, Jul 8, 2019 at 2:40 PM Dan Poltawski < dan.poltawski@tnp.net.uk> wrote:
Hi,
On Sun, 2019-07-07 at 09:31 +0300, Benny Zlotnik wrote:
Any chance you can setup gdb[1] so we can find out where
stuck
exactly?
Yes, abolutely - but I will need some assistance in getting GDB configured in the engine as I am not very familar with it - or how to enable the correct repos to get the debug info.
$ gdb python 54654
[...]
Reading symbols from /lib64/libfreeblpriv3.so...Reading symbols from /lib64/libfreeblpriv3.so...(no debugging symbols found)...done. (no debugging symbols found)...done. Loaded symbols for /lib64/libfreeblpriv3.so 0x00007fcf82256483 in epoll_wait () from /lib64/libc.so.6 Missing separate debuginfos, use: debuginfo-install python- 2.7.5- 80.el7_6.x86_64 (gdb) pt-bt Undefined command: "pt-bt". Try "help".
Also, which version of ovirt are you using?
Using 4.3.4
Can you also check the ceph logs for anything suspicious?
I haven't seen anything so far, but is an entirely resonable possibility this is ceph misoconfiguraiton as we are learning about both tools.
thanks,
Dan
[1] - https://wiki.python.org/moin/DebuggingWithGdb $ gdb python <cinderlib pid> then `py-bt`
On Thu, Jul 4, 2019 at 7:00 PM <dan.poltawski@tnp.net.uk>
wrote:
> > > Can you provide logs? mainly engine.log and cinderlib.log > > > (/var/log/ovirt-engine/cinderlib/cinderlib.log > > > > > > If I create two volumes, the first one succeeds successfully, the > > second one hangs. If I look in the processlist after creating the > > second volume which doesn't succceed, I see the python ./cinderlib- > > client.py create_volume [...] command still running. > > > > On the ceph side, I can see only the one rbd volume. > > > > Logs below: > > > > > > > > --- cinderlib.log -- > > > > 2019-07-04 16:46:30,863 - cinderlib-client - INFO - Fetch backend > > stats [b07698bb-1688-472f-841b-70a9d52a250d] > > 2019-07-04 16:46:56,308 - cinderlib-client - INFO - Creating volume > > '236285cc-ac01-4239-821c-4beadd66923f', with size '2' GB [0b0f0d6f- > > cb20-440a-bacb-7f5ead2b4b4d] > > 2019-07-04 16:47:21,671 - cinderlib-client - INFO - Creating volume > > '84886485-554a-44ca-964c-9758b4a16aae', with size '2' GB [a793bfc9- > > fc37-4711-a144-d74c100cc75b] > > > > --- engine.log --- > > > > 2019-07-04 16:46:54,062+01 INFO > > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default > > task-22) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: > > AddDiskCommand internal: false. Entities affected : ID: 31536d80- > > ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK > > with role type USER > > 2019-07-04 16:46:54,150+01 INFO > >
[org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged
Bloc > > kStorageDiskCommand] (EE-ManagedThreadFactory- commandCoordinator- > > Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: > > AddManagedBlockStorageDiskCommand internal: true. > > 2019-07-04 16:46:56,863+01 INFO > >
[org.ovirt.engine.core.common.utils.cinderlib.CinderlibExecutor
] > > (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f- > > cb20-440a-bacb-7f5ead2b4b4d] cinderlib output: > > 2019-07-04 16:46:56,912+01 INFO > >
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDi
rect > > or] (default task-22) [] EVENT_ID: > > USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was > > successfully added. > > 2019-07-04 16:47:00,126+01 INFO > >
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCall
back > > ] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [0b0f0d6f- > > cb20-440a-bacb-7f5ead2b4b4d] Command 'AddDisk' id: '15fe157d-7adb- > > 4031-9e81-f51aa0b6528f' child commands '[d056397a-7ed9- 4c01-b880- > > dd518421a2c6]' executions were completed, status 'SUCCEEDED' > > 2019-07-04 16:47:01,136+01 INFO > > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- > > ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f- cb20- > > 440a-bacb-7f5ead2b4b4d] Ending command > > 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' > > successfully. > > 2019-07-04 16:47:01,141+01 INFO > >
[org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged
Bloc > > kStorageDiskCommand] (EE-ManagedThreadFactory- engineScheduled- > > Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command > >
'org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged
Bloc > > kStorageDiskCommand' successfully. > > 2019-07-04 16:47:01,145+01 WARN > > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- > > ManagedThreadFactory-engineScheduled-Thread-99) [] VM is null - no > > unlocking > > 2019-07-04 16:47:01,186+01 INFO > >
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDi
rect > > or] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] > > EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' > > was successfully added. > > 2019-07-04 16:47:19,446+01 INFO > > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default > > task-22) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: > > AddDiskCommand internal: false. Entities affected : ID: 31536d80- > > ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK > > with role type USER > > 2019-07-04 16:47:19,464+01 INFO > >
[org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged
Bloc > > kStorageDiskCommand] (EE-ManagedThreadFactory- commandCoordinator- > > Thread-2) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: > > AddManagedBlockStorageDiskCommand internal: true. > > 2019-07-04 16:48:19,501+01 INFO > >
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService]
(EE- > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > > pool 'commandCoordinator' is using 1 threads out of 10, 1 threads > > waiting for tasks. > > 2019-07-04 16:48:19,501+01 INFO > >
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService]
(EE- > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > > pool 'default' is using 0 threads out of 1, 5 threads waiting for > > tasks. > > 2019-07-04 16:48:19,501+01 INFO > >
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService]
(EE- > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > > pool 'engine' is using 0 threads out of 500, 9 threads waiting for > > tasks and 0 tasks in queue. > > 2019-07-04 16:48:19,501+01 INFO > >
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService]
(EE- > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > > pool 'engineScheduled' is using 0 threads out of 100, 100 threads > > waiting for tasks. > > 2019-07-04 16:48:19,501+01 INFO > >
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService]
(EE- > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > > pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 > > threads waiting for tasks. > > 2019-07-04 16:48:19,501+01 INFO > >
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService]
(EE- > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > > pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 threads > > waiting for tasks. > > > > > > > > 2019-07-04 16:46:54,062+01 INFO > > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default > > task-22) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: > > AddDiskCommand internal: false. Entities affected : ID: 31536d80- > > ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK > > with role type USER > > 2019-07-04 16:46:54,150+01 INFO > >
[org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged
Bloc > > kStorageDiskCommand] (EE-ManagedThreadFactory- commandCoordinator- > > Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: > > AddManagedBlockStorageDiskCommand internal: true. > > 2019-07-04 16:46:56,863+01 INFO > >
[org.ovirt.engine.core.common.utils.cinderlib.CinderlibExecutor
] > > (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f- > > cb20-440a-bacb-7f5ead2b4b4d] cinderlib output: > > 2019-07-04 16:46:56,912+01 INFO > >
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDi
rect > > or] (default task-22) [] EVENT_ID: > > USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was > > successfully added. > > 2019-07-04 16:47:00,126+01 INFO > >
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCall
back > > ] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [0b0f0d6f- > > cb20-440a-bacb-7f5ead2b4b4d] Command 'AddDisk' id: '15fe157d-7adb- > > 4031-9e81-f51aa0b6528f' child commands '[d056397a-7ed9- 4c01-b880- > > dd518421a2c6]' executions were completed, status 'SUCCEEDED' > > 2019-07-04 16:47:01,136+01 INFO > > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- > > ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f- cb20- > > 440a-bacb-7f5ead2b4b4d] Ending command > > 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' > > successfully. > > 2019-07-04 16:47:01,141+01 INFO > >
[org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged
Bloc > > kStorageDiskCommand] (EE-ManagedThreadFactory- engineScheduled- > > Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command > >
'org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged
Bloc > > kStorageDiskCommand' successfully. > > 2019-07-04 16:47:01,145+01 WARN > > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- > > ManagedThreadFactory-engineScheduled-Thread-99) [] VM is null - no > > unlocking > > 2019-07-04 16:47:01,186+01 INFO > >
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDi
rect > > or] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] > > EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' > > was successfully added. > > 2019-07-04 16:47:19,446+01 INFO > > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default > > task-22) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: > > AddDiskCommand internal: false. Entities affected : ID: 31536d80- > > ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK > > with role type USER > > 2019-07-04 16:47:19,464+01 INFO > >
[org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged
Bloc > > kStorageDiskCommand] (EE-ManagedThreadFactory- commandCoordinator- > > Thread-2) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: > > AddManagedBlockStorageDiskCommand internal: true. > > 2019-07-04 16:48:19,501+01 INFO > >
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService]
(EE- > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > > pool 'commandCoordinator' is using 1 threads out of 10, 1 threads > > waiting for tasks. > > 2019-07-04 16:48:19,501+01 INFO > >
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService]
(EE- > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > > pool 'default' is using 0 threads out of 1, 5 threads waiting for > > tasks. > > 2019-07-04 16:48:19,501+01 INFO > >
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService]
(EE- > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > > pool 'engine' is using 0 threads out of 500, 9 threads waiting for > > tasks and 0 tasks in queue. > > 2019-07-04 16:48:19,501+01 INFO > >
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService]
(EE- > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > > pool 'engineScheduled' is using 0 threads out of 100, 100 threads > > waiting for tasks. > > 2019-07-04 16:48:19,501+01 INFO > >
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService]
(EE- > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > > pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 > > threads waiting for tasks. > > 2019-07-04 16:48:19,501+01 INFO > >
[org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService]
(EE- > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread > > pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 threads > > waiting for tasks. > > _______________________________________________ > > Users mailing list -- users@ovirt.org > > To unsubscribe send an email to users-leave@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/VW5AZHXGU2YTSB...
The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England & Wales with company number: 07667393 This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error
it's please
notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e- mail if you have received this e-mail by mistake and delete this e- mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
________________________________
The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England & Wales with company number: 07667393
This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e-mail if you have received this e-mail by mistake and delete this e-mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
________________________________ The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England & Wales with company number: 07667393 This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e-mail if you have received this e-mail by mistake and delete this e-mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
Can you try to create mutliple ceph volumes manually via rbd from the engine machine, so we can simulate what cinderlib does without using it, this can be done $ rbd -c ceph.conf create <pool_name>/vol1 --size 100M $ rbd -c ceph.conf create <pool_name>/vol2 --size 100M On Mon, Jul 8, 2019 at 4:58 PM Dan Poltawski <dan.poltawski@tnp.net.uk> wrote:
On Mon, 2019-07-08 at 16:49 +0300, Benny Zlotnik wrote:
Not too useful unfortunately :\ Can you try py-list instead of py-bt? Perhaps it will provide better results
(gdb) py-list 57 if get_errno(ex) != errno.EEXIST: 58 raise 59 return listener 60 61 def do_poll(self, seconds):
62 return self.poll.poll(seconds)
Thanks for you help,
Dan
On Mon, Jul 8, 2019 at 4:41 PM Dan Poltawski < dan.poltawski@tnp.net.uk> wrote:
On Mon, 2019-07-08 at 16:25 +0300, Benny Zlotnik wrote:
Hi,
You have a typo, it's py-bt and I just tried it myself, I only had to install: $ yum install -y python-devel (in addition to the packages specified in the link)
Thanks - this is what I get:
#3 Frame 0x7f2046b59ad0, for file /usr/lib/python2.7/site- packages/eventlet/hubs/epolls.py, line 62, in do_poll (self=<Hub(next_timers=[], clock=<function at remote 0x7f20661059b0>, debug_exceptions=True, debug_blocking_resolution=1, modify=<built- in method modify of select.epoll object at remote 0x7f2048455168>, running=True, debug_blocking=False, listeners={'read': {20: <FdListener(fileno=20, cb=<built-in method switch of greenlet.greenlet object at remote 0x7f2046878410>, spent=False, greenlet=<greenlet.greenlet at remote 0x7f2046878410>, evtype='read', mark_as_closed=<instancemethod at remote 0x7f2046b09500>, tb=<built-in method throw of greenlet.greenlet object at remote 0x7f2046878410>) at remote 0x7f20468cda10>}, 'write': {}}, timers_canceled=0, greenlet=<greenlet.greenlet at remote 0x7f2046af70f0>, closed=[], stopping=False, timers=[(<float at remote 0x2830e20>, <Timer(seconds=<float at remote 0xced610>, tpl=(<built-in method switch of greenlet.greenlet object at remote 0x7f2046934c30>, (), {}), called=F...(truncated) return self.poll.poll(seconds) #6 Frame 0x32fbf30, for file /usr/lib/python2.7/site- packages/eventlet/hubs/poll.py, line 85, in wait (self=<Hub(next_timers=[], clock=<function at remote 0x7f20661059b0>, debug_exceptions=True, debug_blocking_resolution=1, modify=<built- in method modify of select.epoll object at remote 0x7f2048455168>, running=True, debug_blocking=False, listeners={'read': {20: <FdListener(fileno=20, cb=<built-in method switch of greenlet.greenlet object at remote 0x7f2046878410>, spent=False, greenlet=<greenlet.greenlet at remote 0x7f2046878410>, evtype='read', mark_as_closed=<instancemethod at remote 0x7f2046b09500>, tb=<built-in method throw of greenlet.greenlet object at remote 0x7f2046878410>) at remote 0x7f20468cda10>}, 'write': {}}, timers_canceled=0, greenlet=<greenlet.greenlet at remote 0x7f2046af70f0>, closed=[], stopping=False, timers=[(<float at remote 0x2830e20>, <Timer(seconds=<float at remote 0xced610>, tpl=(<built-in method switch of greenlet.greenlet object at remote 0x7f2046934c30>, (), {}), called=False) at r...(truncated) presult = self.do_poll(seconds) #10 Frame 0x7f2046afca00, for file /usr/lib/python2.7/site- packages/eventlet/hubs/hub.py, line 346, in run (self=<Hub(next_timers=[], clock=<function at remote 0x7f20661059b0>, debug_exceptions=True, debug_blocking_resolution=1, modify=<built- in method modify of select.epoll object at remote 0x7f2048455168>, running=True, debug_blocking=False, listeners={'read': {20: <FdListener(fileno=20, cb=<built-in method switch of greenlet.greenlet object at remote 0x7f2046878410>, spent=False, greenlet=<greenlet.greenlet at remote 0x7f2046878410>, evtype='read', mark_as_closed=<instancemethod at remote 0x7f2046b09500>, tb=<built-in method throw of greenlet.greenlet object at remote 0x7f2046878410>) at remote 0x7f20468cda10>}, 'write': {}}, timers_canceled=0, greenlet=<greenlet.greenlet at remote 0x7f2046af70f0>, closed=[], stopping=False, timers=[(<float at remote 0x2830e20>, <Timer(seconds=<float at remote 0xced610>, tpl=(<built-in method switch of greenlet.greenlet object at remote 0x7f2046934c30>, (), {}), called=False) ...(truncated) self.wait(sleep_time)
On Mon, Jul 8, 2019 at 2:40 PM Dan Poltawski < dan.poltawski@tnp.net.uk> wrote:
Hi,
On Sun, 2019-07-07 at 09:31 +0300, Benny Zlotnik wrote:
> Any chance you can setup gdb[1] so we can find out where
it's
stuck > exactly?
Yes, abolutely - but I will need some assistance in getting GDB configured in the engine as I am not very familar with it - or how to enable the correct repos to get the debug info.
$ gdb python 54654
[...]
Reading symbols from /lib64/libfreeblpriv3.so...Reading symbols from /lib64/libfreeblpriv3.so...(no debugging symbols found)...done. (no debugging symbols found)...done. Loaded symbols for /lib64/libfreeblpriv3.so 0x00007fcf82256483 in epoll_wait () from /lib64/libc.so.6 Missing separate debuginfos, use: debuginfo-install python- 2.7.5- 80.el7_6.x86_64 (gdb) pt-bt Undefined command: "pt-bt". Try "help".
> Also, which version of ovirt are you using?
Using 4.3.4
> Can you also check the ceph logs for anything suspicious?
I haven't seen anything so far, but is an entirely resonable possibility this is ceph misoconfiguraiton as we are learning about both tools.
thanks,
Dan
> > > [1] - https://wiki.python.org/moin/DebuggingWithGdb > $ gdb python <cinderlib pid> > then `py-bt` > > On Thu, Jul 4, 2019 at 7:00 PM <dan.poltawski@tnp.net.uk> wrote: > > > > Can you provide logs? mainly engine.log and cinderlib.log > > > > (/var/log/ovirt-engine/cinderlib/cinderlib.log > > > > > > > > > If I create two volumes, the first one succeeds > successfully, the > > > second one hangs. If I look in the processlist after > creating the > > > second volume which doesn't succceed, I see the python > ./cinderlib- > > > client.py create_volume [...] command still running. > > > > > > On the ceph side, I can see only the one rbd volume. > > > > > > Logs below: > > > > > > > > > > > > --- cinderlib.log -- > > > > > > 2019-07-04 16:46:30,863 - cinderlib-client - INFO - Fetch > backend > > > stats [b07698bb-1688-472f-841b-70a9d52a250d] > > > 2019-07-04 16:46:56,308 - cinderlib-client - INFO - > Creating volume > > > '236285cc-ac01-4239-821c-4beadd66923f', with size '2' GB > [0b0f0d6f- > > > cb20-440a-bacb-7f5ead2b4b4d] > > > 2019-07-04 16:47:21,671 - cinderlib-client - INFO - > Creating volume > > > '84886485-554a-44ca-964c-9758b4a16aae', with size '2' GB > [a793bfc9- > > > fc37-4711-a144-d74c100cc75b] > > > > > > --- engine.log --- > > > > > > 2019-07-04 16:46:54,062+01 INFO > > > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] > (default > > > task-22) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running > command: > > > AddDiskCommand internal: false. Entities affected : ID: > 31536d80- > > > ff45-496b-9820-15441d505924 Type: StorageAction group > CREATE_DISK > > > with role type USER > > > 2019-07-04 16:46:54,150+01 INFO > > > > [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged > Bloc > > > kStorageDiskCommand] (EE-ManagedThreadFactory- > commandCoordinator- > > > Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running > command: > > > AddManagedBlockStorageDiskCommand internal: true. > > > 2019-07-04 16:46:56,863+01 INFO > > > > [org.ovirt.engine.core.common.utils.cinderlib.CinderlibExecutor > ] > > > (EE-ManagedThreadFactory-commandCoordinator-Thread-1) > [0b0f0d6f- > > > cb20-440a-bacb-7f5ead2b4b4d] cinderlib output: > > > 2019-07-04 16:46:56,912+01 INFO > > > > [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDi > rect > > > or] (default task-22) [] EVENT_ID: > > > USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was > > > successfully added. > > > 2019-07-04 16:47:00,126+01 INFO > > > > [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCall > back > > > ] (EE-ManagedThreadFactory-engineScheduled-Thread-95) > [0b0f0d6f- > > > cb20-440a-bacb-7f5ead2b4b4d] Command 'AddDisk' id: > '15fe157d-7adb- > > > 4031-9e81-f51aa0b6528f' child commands '[d056397a-7ed9- > 4c01-b880- > > > dd518421a2c6]' executions were completed, status > 'SUCCEEDED' > > > 2019-07-04 16:47:01,136+01 INFO > > > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] > (EE- > > > ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f- > cb20- > > > 440a-bacb-7f5ead2b4b4d] Ending command > > > 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' > > > successfully. > > > 2019-07-04 16:47:01,141+01 INFO > > > > [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged > Bloc > > > kStorageDiskCommand] (EE-ManagedThreadFactory- > engineScheduled- > > > Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending > command > > > > 'org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged > Bloc > > > kStorageDiskCommand' successfully. > > > 2019-07-04 16:47:01,145+01 WARN > > > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] > (EE- > > > ManagedThreadFactory-engineScheduled-Thread-99) [] VM is > null - no > > > unlocking > > > 2019-07-04 16:47:01,186+01 INFO > > > > [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDi > rect > > > or] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] > > > EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk > 'test0' > > > was successfully added. > > > 2019-07-04 16:47:19,446+01 INFO > > > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] > (default > > > task-22) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running > command: > > > AddDiskCommand internal: false. Entities affected : ID: > 31536d80- > > > ff45-496b-9820-15441d505924 Type: StorageAction group > CREATE_DISK > > > with role type USER > > > 2019-07-04 16:47:19,464+01 INFO > > > > [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged > Bloc > > > kStorageDiskCommand] (EE-ManagedThreadFactory- > commandCoordinator- > > > Thread-2) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running > command: > > > AddManagedBlockStorageDiskCommand internal: true. > > > 2019-07-04 16:48:19,501+01 INFO > > > > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] > (EE- > > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] > Thread > > > pool 'commandCoordinator' is using 1 threads out of 10, 1 > threads > > > waiting for tasks. > > > 2019-07-04 16:48:19,501+01 INFO > > > > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] > (EE- > > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] > Thread > > > pool 'default' is using 0 threads out of 1, 5 threads > waiting for > > > tasks. > > > 2019-07-04 16:48:19,501+01 INFO > > > > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] > (EE- > > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] > Thread > > > pool 'engine' is using 0 threads out of 500, 9 threads > waiting for > > > tasks and 0 tasks in queue. > > > 2019-07-04 16:48:19,501+01 INFO > > > > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] > (EE- > > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] > Thread > > > pool 'engineScheduled' is using 0 threads out of 100, 100 > threads > > > waiting for tasks. > > > 2019-07-04 16:48:19,501+01 INFO > > > > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] > (EE- > > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] > Thread > > > pool 'engineThreadMonitoring' is using 1 threads out of 1, > 0 > > > threads waiting for tasks. > > > 2019-07-04 16:48:19,501+01 INFO > > > > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] > (EE- > > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] > Thread > > > pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 > threads > > > waiting for tasks. > > > > > > > > > > > > 2019-07-04 16:46:54,062+01 INFO > > > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] > (default > > > task-22) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running > command: > > > AddDiskCommand internal: false. Entities affected : ID: > 31536d80- > > > ff45-496b-9820-15441d505924 Type: StorageAction group > CREATE_DISK > > > with role type USER > > > 2019-07-04 16:46:54,150+01 INFO > > > > [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged > Bloc > > > kStorageDiskCommand] (EE-ManagedThreadFactory- > commandCoordinator- > > > Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running > command: > > > AddManagedBlockStorageDiskCommand internal: true. > > > 2019-07-04 16:46:56,863+01 INFO > > > > [org.ovirt.engine.core.common.utils.cinderlib.CinderlibExecutor > ] > > > (EE-ManagedThreadFactory-commandCoordinator-Thread-1) > [0b0f0d6f- > > > cb20-440a-bacb-7f5ead2b4b4d] cinderlib output: > > > 2019-07-04 16:46:56,912+01 INFO > > > > [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDi > rect > > > or] (default task-22) [] EVENT_ID: > > > USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was > > > successfully added. > > > 2019-07-04 16:47:00,126+01 INFO > > > > [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCall > back > > > ] (EE-ManagedThreadFactory-engineScheduled-Thread-95) > [0b0f0d6f- > > > cb20-440a-bacb-7f5ead2b4b4d] Command 'AddDisk' id: > '15fe157d-7adb- > > > 4031-9e81-f51aa0b6528f' child commands '[d056397a-7ed9- > 4c01-b880- > > > dd518421a2c6]' executions were completed, status > 'SUCCEEDED' > > > 2019-07-04 16:47:01,136+01 INFO > > > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] > (EE- > > > ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f- > cb20- > > > 440a-bacb-7f5ead2b4b4d] Ending command > > > 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' > > > successfully. > > > 2019-07-04 16:47:01,141+01 INFO > > > > [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged > Bloc > > > kStorageDiskCommand] (EE-ManagedThreadFactory- > engineScheduled- > > > Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending > command > > > > 'org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged > Bloc > > > kStorageDiskCommand' successfully. > > > 2019-07-04 16:47:01,145+01 WARN > > > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] > (EE- > > > ManagedThreadFactory-engineScheduled-Thread-99) [] VM is > null - no > > > unlocking > > > 2019-07-04 16:47:01,186+01 INFO > > > > [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDi > rect > > > or] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] > > > EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk > 'test0' > > > was successfully added. > > > 2019-07-04 16:47:19,446+01 INFO > > > [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] > (default > > > task-22) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running > command: > > > AddDiskCommand internal: false. Entities affected : ID: > 31536d80- > > > ff45-496b-9820-15441d505924 Type: StorageAction group > CREATE_DISK > > > with role type USER > > > 2019-07-04 16:47:19,464+01 INFO > > > > [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManaged > Bloc > > > kStorageDiskCommand] (EE-ManagedThreadFactory- > commandCoordinator- > > > Thread-2) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running > command: > > > AddManagedBlockStorageDiskCommand internal: true. > > > 2019-07-04 16:48:19,501+01 INFO > > > > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] > (EE- > > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] > Thread > > > pool 'commandCoordinator' is using 1 threads out of 10, 1 > threads > > > waiting for tasks. > > > 2019-07-04 16:48:19,501+01 INFO > > > > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] > (EE- > > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] > Thread > > > pool 'default' is using 0 threads out of 1, 5 threads > waiting for > > > tasks. > > > 2019-07-04 16:48:19,501+01 INFO > > > > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] > (EE- > > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] > Thread > > > pool 'engine' is using 0 threads out of 500, 9 threads > waiting for > > > tasks and 0 tasks in queue. > > > 2019-07-04 16:48:19,501+01 INFO > > > > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] > (EE- > > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] > Thread > > > pool 'engineScheduled' is using 0 threads out of 100, 100 > threads > > > waiting for tasks. > > > 2019-07-04 16:48:19,501+01 INFO > > > > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] > (EE- > > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] > Thread > > > pool 'engineThreadMonitoring' is using 1 threads out of 1, > 0 > > > threads waiting for tasks. > > > 2019-07-04 16:48:19,501+01 INFO > > > > [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] > (EE- > > > ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] > Thread > > > pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 > threads > > > waiting for tasks. > > > _______________________________________________ > > > Users mailing list -- users@ovirt.org > > > To unsubscribe send an email to users-leave@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/VW5AZHXGU2YTSB...
The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England &
with company number: 07667393 This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error
Wales please
notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e- mail if you have received this e-mail by mistake and delete this e- mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
________________________________
The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England & Wales with company number: 07667393
This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e-mail if you have received this e-mail by mistake and delete this e-mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
________________________________
The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England & Wales with company number: 07667393
This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e-mail if you have received this e-mail by mistake and delete this e-mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
On Mon, 2019-07-08 at 18:53 +0300, Benny Zlotnik wrote:
Can you try to create mutliple ceph volumes manually via rbd from the engine machine, so we can simulate what cinderlib does without using it, this can be done $ rbd -c ceph.conf create <pool_name>/vol1 --size 100M $ rbd -c ceph.conf create <pool_name>/vol2 --size 100M
Thanks - I did this and it allowed me to get to the bottom of the problem. Those commands were freezing and after some investigation and reconfiguration I think it was a problem was with connectivity to the ceph osds, where as connectivity to the mons was 'working'. I've now managed to succesfully create/mount/delete volumes! Dan ________________________________ The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England & Wales with company number: 07667393 This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e-mail if you have received this e-mail by mistake and delete this e-mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
On Tue, 2019-07-09 at 08:00 +0100, Dan Poltawski wrote:
I've now managed to succesfully create/mount/delete volumes!
However, I'm seeing live migrations stay stuck. Is this supported? (gdb) py-list 345 client.conf_set('rados_osd_op_timeout', timeout) 346 client.conf_set('rados_mon_op_timeout', timeout) 347 client.conf_set('client_mount_timeout', timeout) 348 349 client.connect()
350 ioctx = client.open_ioctx(pool) 351 return client, ioctx 352 except self.rados.Error: 353 msg = _("Error connecting to ceph cluster.") 354 LOG.exception(msg) 355 client.shutdown()
(gdb) py-bt #15 Frame 0x3ea0e50, for file /usr/lib/python2.7/site- packages/cinder/volume/drivers/rbd.py, line 350, in _do_conn (pool='storage-ssd', remote=None, timeout=-1, name='ceph', conf='/etc/ceph/ceph.conf', user='ovirt', client=<rados.Rados at remote 0x7fb1f4f83a60>) ioctx = client.open_ioctx(pool) #20 Frame 0x3ea4620, for file /usr/lib/python2.7/site- packages/retrying.py, line 217, in call (self=<Retrying(_retry_on_exception=<function at remote 0x7fb1f4f23488>, _wait_exponential_max=1073741823, _wait_incrementing_start=0, stop=<function at remote 0x7fb1f4f23578>, _stop_max_attempt_number=5, _wait_incrementing_increment=100, _wait_random_max=1000, _retry_on_result=<instancemethod at remote 0x7fb1f51da550>, _stop_max_delay=100, _wait_fixed=1000, _wrap_exception=False, _wait_random_min=0, _wait_exponential_multiplier=1, wait=<function at remote 0x7fb1f4f23500>) at remote 0x7fb1f4f1ae90>, fn=<function at remote 0x7fb1f4f23668>, args=(None, None, None), kwargs={}, start_time=1562658179214, attempt_number=1) attempt = Attempt(fn(*args, **kwargs), attempt_number, False) #25 Frame 0x3e49d50, for file /usr/lib/python2.7/site- packages/cinder/utils.py, line 818, in _wrapper (args=(None, None, None), kwargs={}, r=<Retrying(_retry_on_exception=<function at remote 0x7fb1f4f23488>, _wait_exponential_max=1073741823, _wait_incrementing_start=0, stop=<function at remote 0x7fb1f4f23578>, _stop_max_attempt_number=5, _wait_incrementing_increment=100, _wait_random_max=1000, _retry_on_result=<instancemethod at remote 0x7fb1f51da550>, _stop_max_delay=100, _wait_fixed=1000, _wrap_exception=False, _wait_random_min=0, _wait_exponential_multiplier=1, wait=<function at remote 0x7fb1f4f23500>) at remote 0x7fb1f4f1ae90>) return r.call(f, *args, **kwargs) #29 Frame 0x7fb1f4f9a810, for file /usr/lib/python2.7/site- packages/cinder/volume/drivers/rbd.py, line 358, in _connect_to_rados (self=<RBDDriver(_target_names=[], rbd=<module at remote 0x7fb20583e830>, _is_replication_enabled=False, _execute=<function at remote 0x7fb2041242a8>, _active_config={'name': 'ceph', 'conf': '/etc/ceph/ceph.conf', 'user': 'ovirt'}, _active_backend_id=None, _initialized=False, db=<DBAPI(_backend=<module at remote 0x7fb203f8d520>, qos_specs_get=<instancemethod at remote 0x7fb1f677d460>, _lock=<Semaphore(counter=1, _waiters=<collections.deque at remote 0x7fb1f5246d70>) at remote 0x7fb1f5205bd0>, _wrap_db_kwargs={'max_retries': 20, 'inc_retry_interval': True, 'retry_interval': 1, 'max_retry_interval': 10}, _backend_mapping={'sqlalchemy': 'cinder.db.sqlalchemy.api'}, _backend_name='sqlalchemy', use_db_reconnect=False, get_by_id=<instancemethod at remote 0x7fb1f61d8050>, volume_type_get=<instancemethod at remote 0x7fb1f61c0f50>) at remote 0x7fb2003aab10>, target_mapping={'tgtadm': 'cinder.vol...(truncated) return _do_conn(pool, remote, timeout) #33 Frame 0x7fb1f4f5b220, for file /usr/lib/python2.7/site- packages/cinder/volume/drivers/rbd.py, line 177, in __init__ (self=<RADOSClient(driver=<RBDDriver(_target_names=[], rbd=<module at remote 0x7fb20583e830>, _is_replication_enabled=False, _execute=<function at remote 0x7fb2041242a8>, _active_config={'name': 'ceph', 'conf': '/etc/ceph/ceph.conf', 'user': 'ovirt'}, _active_backend_id=None, _initialized=False, db=<DBAPI(_backend=<module at remote 0x7fb203f8d520>, qos_specs_get=<instancemethod at remote 0x7fb1f677d460>, _lock=<Semaphore(counter=1, _waiters=<collections.deque at remote 0x7fb1f5246d70>) at remote 0x7fb1f5205bd0>, _wrap_db_kwargs={'max_retries': 20, 'inc_retry_interval': True, 'retry_interval': 1, 'max_retry_interval': 10}, _backend_mapping={'sqlalchemy': 'cinder.db.sqlalchemy.api'}, _backend_name='sqlalchemy', use_db_reconnect=False, get_by_id=<instancemethod at remote 0x7fb1f61d8050>, volume_type_get=<instancemethod at remote 0x7fb1f61c0f50>) at remote 0x7fb2003aab10>, target_mapping={'tgtadm': ...(truncated) self.cluster, self.ioctx = driver._connect_to_rados(pool) #44 Frame 0x7fb1f4f9a620, for file /usr/lib/python2.7/site- packages/cinder/volume/drivers/rbd.py, line 298, in check_for_setup_error (self=<RBDDriver(_target_names=[], rbd=<module at remote 0x7fb20583e830>, _is_replication_enabled=False, _execute=<function at remote 0x7fb2041242a8>, _active_config={'name': 'ceph', 'conf': '/etc/ceph/ceph.conf', 'user': 'ovirt'}, _active_backend_id=None, _initialized=False, db=<DBAPI(_backend=<module at remote 0x7fb203f8d520>, qos_specs_get=<instancemethod at remote 0x7fb1f677d460>, _lock=<Semaphore(counter=1, _waiters=<collections.deque at remote 0x7fb1f5246d70>) at remote 0x7fb1f5205bd0>, _wrap_db_kwargs={'max_retries': 20, 'inc_retry_interval': True, 'retry_interval': 1, 'max_retry_interval': 10}, _backend_mapping={'sqlalchemy': 'cinder.db.sqlalchemy.api'}, _backend_name='sqlalchemy', use_db_reconnect=False, get_by_id=<instancemethod at remote 0x7fb1f61d8050>, volume_type_get=<instancemethod at remote 0x7fb1f61c0f50>) at remote 0x7fb2003aab10>, target_mapping={'tgtadm': 'cinder...(truncated) with RADOSClient(self): #48 Frame 0x3e5bef0, for file /usr/lib/python2.7/site- packages/cinderlib/cinderlib.py, line 88, in __init__ (self=<Backend(driver=<RBDDriver(_target_names=[], rbd=<module at remote 0x7fb20583e830>, _is_replication_enabled=False, _execute=<function at remote 0x7fb2041242a8>, _active_config={'name': 'ceph', 'conf': '/etc/ceph/ceph.conf', 'user': 'ovirt'}, _active_backend_id=None, _initialized=False, db=<DBAPI(_backend=<module at remote 0x7fb203f8d520>, qos_specs_get=<instancemethod at remote 0x7fb1f677d460>, _lock=<Semaphore(counter=1, _waiters=<collections.deque at remote 0x7fb1f5246d70>) at remote 0x7fb1f5205bd0>, _wrap_db_kwargs={'max_retries': 20, 'inc_retry_interval': True, 'retry_interval': 1, 'max_retry_interval': 10}, _backend_mapping={'sqlalchemy': 'cinder.db.sqlalchemy.api'}, _backend_name='sqlalchemy', use_db_reconnect=False, get_by_id=<instancemethod at remote 0x7fb1f61d8050>, volume_type_get=<instancemethod at remote 0x7fb1f61c0f50>) at remote 0x7fb2003aab10>, target_mapping={'tgtadm': 'cinder.volume.t...(truncated) self.driver.check_for_setup_error() #58 Frame 0x3d15cf0, for file ./cinderlib-client.py, line 210, in load_backend (args=<Namespace(driver='{"volume_backend_name":"ceph- storage-ssd-ovirt","volume---Type <return> to continue, or q <return> to quit--- _driver":"cinder.volume.drivers.rbd.RBDDriver","rbd_ceph_conf":"/etc/ce ph/ceph.conf","rbd_user":"ovirt","rbd_keyring_conf":"/etc/ceph/ceph.cli ent.ovirt.keyring","rbd_pool":"storage- ssd","use_multipath_for_image_xfer":"true"}', db_url='postgresql+psycopg2://ovirt_cinderlib:ViRsNB3Dnwy5wmL0lLuDEq@lo calhost:5432/ovirt_cinderlib', correlation_id='7733e7cc', command=<function at remote 0x7fb1f52725f0>, volume_id='9d858d39-bbd4- 4cbe-9f2c-5bef25ed0525', connector_info='{"ip":null,"host":"compute00.hq.tnp.infra","os_type":"l inux2","platform":"x86_64","initiator":"iqn.1994- 05.com.redhat:c6ab662d439c","multipath":true,"do_local_attach":false}') at remote 0x7fb1f5215910>, persistence_config={'connection': 'postgresql+psycopg2://ovirt_cinderlib:ViRsNB3Dnwy5wmL0lLuDEq@localhost :5432/ovirt_cinderlib', 'storage': 'db'}) Python Exception <type 'exceptions.IOError'> [Errno 2] No such file or directory: './cinderlib-client.py': Error occurred in Python command: [Errno 2] No such file or directory: './cinderlib-client.py' ________________________________ The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England & Wales with company number: 07667393 This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e-mail if you have received this e-mail by mistake and delete this e-mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
VM live migration is supported and should work Can you add engine and cinderlib logs? On Tue, Jul 9, 2019 at 11:01 AM Dan Poltawski <dan.poltawski@tnp.net.uk> wrote:
On Tue, 2019-07-09 at 08:00 +0100, Dan Poltawski wrote:
I've now managed to succesfully create/mount/delete volumes!
However, I'm seeing live migrations stay stuck. Is this supported?
(gdb) py-list 345 client.conf_set('rados_osd_op_timeout', timeout) 346 client.conf_set('rados_mon_op_timeout', timeout) 347 client.conf_set('client_mount_timeout', timeout) 348 349 client.connect()
350 ioctx = client.open_ioctx(pool) 351 return client, ioctx 352 except self.rados.Error: 353 msg = _("Error connecting to ceph cluster.") 354 LOG.exception(msg) 355 client.shutdown()
(gdb) py-bt #15 Frame 0x3ea0e50, for file /usr/lib/python2.7/site- packages/cinder/volume/drivers/rbd.py, line 350, in _do_conn (pool='storage-ssd', remote=None, timeout=-1, name='ceph', conf='/etc/ceph/ceph.conf', user='ovirt', client=<rados.Rados at remote 0x7fb1f4f83a60>) ioctx = client.open_ioctx(pool) #20 Frame 0x3ea4620, for file /usr/lib/python2.7/site- packages/retrying.py, line 217, in call (self=<Retrying(_retry_on_exception=<function at remote 0x7fb1f4f23488>, _wait_exponential_max=1073741823, _wait_incrementing_start=0, stop=<function at remote 0x7fb1f4f23578>, _stop_max_attempt_number=5, _wait_incrementing_increment=100, _wait_random_max=1000, _retry_on_result=<instancemethod at remote 0x7fb1f51da550>, _stop_max_delay=100, _wait_fixed=1000, _wrap_exception=False, _wait_random_min=0, _wait_exponential_multiplier=1, wait=<function at remote 0x7fb1f4f23500>) at remote 0x7fb1f4f1ae90>, fn=<function at remote 0x7fb1f4f23668>, args=(None, None, None), kwargs={}, start_time=1562658179214, attempt_number=1) attempt = Attempt(fn(*args, **kwargs), attempt_number, False) #25 Frame 0x3e49d50, for file /usr/lib/python2.7/site- packages/cinder/utils.py, line 818, in _wrapper (args=(None, None, None), kwargs={}, r=<Retrying(_retry_on_exception=<function at remote 0x7fb1f4f23488>, _wait_exponential_max=1073741823, _wait_incrementing_start=0, stop=<function at remote 0x7fb1f4f23578>, _stop_max_attempt_number=5, _wait_incrementing_increment=100, _wait_random_max=1000, _retry_on_result=<instancemethod at remote 0x7fb1f51da550>, _stop_max_delay=100, _wait_fixed=1000, _wrap_exception=False, _wait_random_min=0, _wait_exponential_multiplier=1, wait=<function at remote 0x7fb1f4f23500>) at remote 0x7fb1f4f1ae90>) return r.call(f, *args, **kwargs) #29 Frame 0x7fb1f4f9a810, for file /usr/lib/python2.7/site- packages/cinder/volume/drivers/rbd.py, line 358, in _connect_to_rados (self=<RBDDriver(_target_names=[], rbd=<module at remote 0x7fb20583e830>, _is_replication_enabled=False, _execute=<function at remote 0x7fb2041242a8>, _active_config={'name': 'ceph', 'conf': '/etc/ceph/ceph.conf', 'user': 'ovirt'}, _active_backend_id=None, _initialized=False, db=<DBAPI(_backend=<module at remote 0x7fb203f8d520>, qos_specs_get=<instancemethod at remote 0x7fb1f677d460>, _lock=<Semaphore(counter=1, _waiters=<collections.deque at remote 0x7fb1f5246d70>) at remote 0x7fb1f5205bd0>, _wrap_db_kwargs={'max_retries': 20, 'inc_retry_interval': True, 'retry_interval': 1, 'max_retry_interval': 10}, _backend_mapping={'sqlalchemy': 'cinder.db.sqlalchemy.api'}, _backend_name='sqlalchemy', use_db_reconnect=False, get_by_id=<instancemethod at remote 0x7fb1f61d8050>, volume_type_get=<instancemethod at remote 0x7fb1f61c0f50>) at remote 0x7fb2003aab10>, target_mapping={'tgtadm': 'cinder.vol...(truncated) return _do_conn(pool, remote, timeout) #33 Frame 0x7fb1f4f5b220, for file /usr/lib/python2.7/site- packages/cinder/volume/drivers/rbd.py, line 177, in __init__ (self=<RADOSClient(driver=<RBDDriver(_target_names=[], rbd=<module at remote 0x7fb20583e830>, _is_replication_enabled=False, _execute=<function at remote 0x7fb2041242a8>, _active_config={'name': 'ceph', 'conf': '/etc/ceph/ceph.conf', 'user': 'ovirt'}, _active_backend_id=None, _initialized=False, db=<DBAPI(_backend=<module at remote 0x7fb203f8d520>, qos_specs_get=<instancemethod at remote 0x7fb1f677d460>, _lock=<Semaphore(counter=1, _waiters=<collections.deque at remote 0x7fb1f5246d70>) at remote 0x7fb1f5205bd0>, _wrap_db_kwargs={'max_retries': 20, 'inc_retry_interval': True, 'retry_interval': 1, 'max_retry_interval': 10}, _backend_mapping={'sqlalchemy': 'cinder.db.sqlalchemy.api'}, _backend_name='sqlalchemy', use_db_reconnect=False, get_by_id=<instancemethod at remote 0x7fb1f61d8050>, volume_type_get=<instancemethod at remote 0x7fb1f61c0f50>) at remote 0x7fb2003aab10>, target_mapping={'tgtadm': ...(truncated) self.cluster, self.ioctx = driver._connect_to_rados(pool) #44 Frame 0x7fb1f4f9a620, for file /usr/lib/python2.7/site- packages/cinder/volume/drivers/rbd.py, line 298, in check_for_setup_error (self=<RBDDriver(_target_names=[], rbd=<module at remote 0x7fb20583e830>, _is_replication_enabled=False, _execute=<function at remote 0x7fb2041242a8>, _active_config={'name': 'ceph', 'conf': '/etc/ceph/ceph.conf', 'user': 'ovirt'}, _active_backend_id=None, _initialized=False, db=<DBAPI(_backend=<module at remote 0x7fb203f8d520>, qos_specs_get=<instancemethod at remote 0x7fb1f677d460>, _lock=<Semaphore(counter=1, _waiters=<collections.deque at remote 0x7fb1f5246d70>) at remote 0x7fb1f5205bd0>, _wrap_db_kwargs={'max_retries': 20, 'inc_retry_interval': True, 'retry_interval': 1, 'max_retry_interval': 10}, _backend_mapping={'sqlalchemy': 'cinder.db.sqlalchemy.api'}, _backend_name='sqlalchemy', use_db_reconnect=False, get_by_id=<instancemethod at remote 0x7fb1f61d8050>, volume_type_get=<instancemethod at remote 0x7fb1f61c0f50>) at remote 0x7fb2003aab10>, target_mapping={'tgtadm': 'cinder...(truncated) with RADOSClient(self): #48 Frame 0x3e5bef0, for file /usr/lib/python2.7/site- packages/cinderlib/cinderlib.py, line 88, in __init__ (self=<Backend(driver=<RBDDriver(_target_names=[], rbd=<module at remote 0x7fb20583e830>, _is_replication_enabled=False, _execute=<function at remote 0x7fb2041242a8>, _active_config={'name': 'ceph', 'conf': '/etc/ceph/ceph.conf', 'user': 'ovirt'}, _active_backend_id=None, _initialized=False, db=<DBAPI(_backend=<module at remote 0x7fb203f8d520>, qos_specs_get=<instancemethod at remote 0x7fb1f677d460>, _lock=<Semaphore(counter=1, _waiters=<collections.deque at remote 0x7fb1f5246d70>) at remote 0x7fb1f5205bd0>, _wrap_db_kwargs={'max_retries': 20, 'inc_retry_interval': True, 'retry_interval': 1, 'max_retry_interval': 10}, _backend_mapping={'sqlalchemy': 'cinder.db.sqlalchemy.api'}, _backend_name='sqlalchemy', use_db_reconnect=False, get_by_id=<instancemethod at remote 0x7fb1f61d8050>, volume_type_get=<instancemethod at remote 0x7fb1f61c0f50>) at remote 0x7fb2003aab10>, target_mapping={'tgtadm': 'cinder.volume.t...(truncated) self.driver.check_for_setup_error() #58 Frame 0x3d15cf0, for file ./cinderlib-client.py, line 210, in load_backend (args=<Namespace(driver='{"volume_backend_name":"ceph- storage-ssd-ovirt","volume---Type <return> to continue, or q <return> to quit--- _driver":"cinder.volume.drivers.rbd.RBDDriver","rbd_ceph_conf":"/etc/ce ph/ceph.conf","rbd_user":"ovirt","rbd_keyring_conf":"/etc/ceph/ceph.cli ent.ovirt.keyring","rbd_pool":"storage- ssd","use_multipath_for_image_xfer":"true"}', db_url='postgresql+psycopg2://ovirt_cinderlib:ViRsNB3Dnwy5wmL0lLuDEq@lo calhost:5432/ovirt_cinderlib', correlation_id='7733e7cc', command=<function at remote 0x7fb1f52725f0>, volume_id='9d858d39-bbd4- 4cbe-9f2c-5bef25ed0525', connector_info='{"ip":null,"host":"compute00.hq.tnp.infra","os_type":"l inux2","platform":"x86_64","initiator":"iqn.1994- 05.com.redhat:c6ab662d439c","multipath":true,"do_local_attach":false}') at remote 0x7fb1f5215910>, persistence_config={'connection': 'postgresql+psycopg2://ovirt_cinderlib:ViRsNB3Dnwy5wmL0lLuDEq@localhost :5432/ovirt_cinderlib', 'storage': 'db'}) Python Exception <type 'exceptions.IOError'> [Errno 2] No such file or directory: './cinderlib-client.py': Error occurred in Python command: [Errno 2] No such file or directory: './cinderlib-client.py'
________________________________
The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England & Wales with company number: 07667393
This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e-mail if you have received this e-mail by mistake and delete this e-mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
On Tue, 2019-07-09 at 11:12 +0300, Benny Zlotnik wrote:
VM live migration is supported and should work Can you add engine and cinderlib logs?
Sorry - looks like once again this was a misconfig by me on the ceph side.. Is it possible to migrate existing vms to managed block storage? Also is it possible to host the hosted engine on this storage? Thanks Again for your help, Dan
On Tue, Jul 9, 2019 at 11:01 AM Dan Poltawski < dan.poltawski@tnp.net.uk> wrote:
On Tue, 2019-07-09 at 08:00 +0100, Dan Poltawski wrote:
I've now managed to succesfully create/mount/delete volumes!
However, I'm seeing live migrations stay stuck. Is this supported?
(gdb) py-list 345 client.conf_set('rados_osd_op_timeout', timeout) 346 client.conf_set('rados_mon_op_timeout', timeout) 347 client.conf_set('client_mount_timeout', timeout) 348 349 client.connect()
350 ioctx = client.open_ioctx(pool) 351 return client, ioctx 352 except self.rados.Error: 353 msg = _("Error connecting to ceph cluster.") 354 LOG.exception(msg) 355 client.shutdown()
(gdb) py-bt #15 Frame 0x3ea0e50, for file /usr/lib/python2.7/site- packages/cinder/volume/drivers/rbd.py, line 350, in _do_conn (pool='storage-ssd', remote=None, timeout=-1, name='ceph', conf='/etc/ceph/ceph.conf', user='ovirt', client=<rados.Rados at remote 0x7fb1f4f83a60>) ioctx = client.open_ioctx(pool) #20 Frame 0x3ea4620, for file /usr/lib/python2.7/site- packages/retrying.py, line 217, in call (self=<Retrying(_retry_on_exception=<function at remote 0x7fb1f4f23488>, _wait_exponential_max=1073741823, _wait_incrementing_start=0, stop=<function at remote 0x7fb1f4f23578>, _stop_max_attempt_number=5, _wait_incrementing_increment=100, _wait_random_max=1000, _retry_on_result=<instancemethod at remote 0x7fb1f51da550>, _stop_max_delay=100, _wait_fixed=1000, _wrap_exception=False, _wait_random_min=0, _wait_exponential_multiplier=1, wait=<function at remote 0x7fb1f4f23500>) at remote 0x7fb1f4f1ae90>, fn=<function at remote 0x7fb1f4f23668>, args=(None, None, None), kwargs={}, start_time=1562658179214, attempt_number=1) attempt = Attempt(fn(*args, **kwargs), attempt_number, False) #25 Frame 0x3e49d50, for file /usr/lib/python2.7/site- packages/cinder/utils.py, line 818, in _wrapper (args=(None, None, None), kwargs={}, r=<Retrying(_retry_on_exception=<function at remote 0x7fb1f4f23488>, _wait_exponential_max=1073741823, _wait_incrementing_start=0, stop=<function at remote 0x7fb1f4f23578>, _stop_max_attempt_number=5, _wait_incrementing_increment=100, _wait_random_max=1000, _retry_on_result=<instancemethod at remote 0x7fb1f51da550>, _stop_max_delay=100, _wait_fixed=1000, _wrap_exception=False, _wait_random_min=0, _wait_exponential_multiplier=1, wait=<function at remote 0x7fb1f4f23500>) at remote 0x7fb1f4f1ae90>) return r.call(f, *args, **kwargs) #29 Frame 0x7fb1f4f9a810, for file /usr/lib/python2.7/site- packages/cinder/volume/drivers/rbd.py, line 358, in _connect_to_rados (self=<RBDDriver(_target_names=[], rbd=<module at remote 0x7fb20583e830>, _is_replication_enabled=False, _execute=<function at remote 0x7fb2041242a8>, _active_config={'name': 'ceph', 'conf': '/etc/ceph/ceph.conf', 'user': 'ovirt'}, _active_backend_id=None, _initialized=False, db=<DBAPI(_backend=<module at remote 0x7fb203f8d520>, qos_specs_get=<instancemethod at remote 0x7fb1f677d460>, _lock=<Semaphore(counter=1, _waiters=<collections.deque at remote 0x7fb1f5246d70>) at remote 0x7fb1f5205bd0>, _wrap_db_kwargs={'max_retries': 20, 'inc_retry_interval': True, 'retry_interval': 1, 'max_retry_interval': 10}, _backend_mapping={'sqlalchemy': 'cinder.db.sqlalchemy.api'}, _backend_name='sqlalchemy', use_db_reconnect=False, get_by_id=<instancemethod at remote 0x7fb1f61d8050>, volume_type_get=<instancemethod at remote 0x7fb1f61c0f50>) at remote 0x7fb2003aab10>, target_mapping={'tgtadm': 'cinder.vol...(truncated) return _do_conn(pool, remote, timeout) #33 Frame 0x7fb1f4f5b220, for file /usr/lib/python2.7/site- packages/cinder/volume/drivers/rbd.py, line 177, in __init__ (self=<RADOSClient(driver=<RBDDriver(_target_names=[], rbd=<module at remote 0x7fb20583e830>, _is_replication_enabled=False, _execute=<function at remote 0x7fb2041242a8>, _active_config={'name': 'ceph', 'conf': '/etc/ceph/ceph.conf', 'user': 'ovirt'}, _active_backend_id=None, _initialized=False, db=<DBAPI(_backend=<module at remote 0x7fb203f8d520>, qos_specs_get=<instancemethod at remote 0x7fb1f677d460>, _lock=<Semaphore(counter=1, _waiters=<collections.deque at remote 0x7fb1f5246d70>) at remote 0x7fb1f5205bd0>, _wrap_db_kwargs={'max_retries': 20, 'inc_retry_interval': True, 'retry_interval': 1, 'max_retry_interval': 10}, _backend_mapping={'sqlalchemy': 'cinder.db.sqlalchemy.api'}, _backend_name='sqlalchemy', use_db_reconnect=False, get_by_id=<instancemethod at remote 0x7fb1f61d8050>, volume_type_get=<instancemethod at remote 0x7fb1f61c0f50>) at remote 0x7fb2003aab10>, target_mapping={'tgtadm': ...(truncated) self.cluster, self.ioctx = driver._connect_to_rados(pool) #44 Frame 0x7fb1f4f9a620, for file /usr/lib/python2.7/site- packages/cinder/volume/drivers/rbd.py, line 298, in check_for_setup_error (self=<RBDDriver(_target_names=[], rbd=<module at remote 0x7fb20583e830>, _is_replication_enabled=False, _execute=<function at remote 0x7fb2041242a8>, _active_config={'name': 'ceph', 'conf': '/etc/ceph/ceph.conf', 'user': 'ovirt'}, _active_backend_id=None, _initialized=False, db=<DBAPI(_backend=<module at remote 0x7fb203f8d520>, qos_specs_get=<instancemethod at remote 0x7fb1f677d460>, _lock=<Semaphore(counter=1, _waiters=<collections.deque at remote 0x7fb1f5246d70>) at remote 0x7fb1f5205bd0>, _wrap_db_kwargs={'max_retries': 20, 'inc_retry_interval': True, 'retry_interval': 1, 'max_retry_interval': 10}, _backend_mapping={'sqlalchemy': 'cinder.db.sqlalchemy.api'}, _backend_name='sqlalchemy', use_db_reconnect=False, get_by_id=<instancemethod at remote 0x7fb1f61d8050>, volume_type_get=<instancemethod at remote 0x7fb1f61c0f50>) at remote 0x7fb2003aab10>, target_mapping={'tgtadm': 'cinder...(truncated) with RADOSClient(self): #48 Frame 0x3e5bef0, for file /usr/lib/python2.7/site- packages/cinderlib/cinderlib.py, line 88, in __init__ (self=<Backend(driver=<RBDDriver(_target_names=[], rbd=<module at remote 0x7fb20583e830>, _is_replication_enabled=False, _execute=<function at remote 0x7fb2041242a8>, _active_config={'name': 'ceph', 'conf': '/etc/ceph/ceph.conf', 'user': 'ovirt'}, _active_backend_id=None, _initialized=False, db=<DBAPI(_backend=<module at remote 0x7fb203f8d520>, qos_specs_get=<instancemethod at remote 0x7fb1f677d460>, _lock=<Semaphore(counter=1, _waiters=<collections.deque at remote 0x7fb1f5246d70>) at remote 0x7fb1f5205bd0>, _wrap_db_kwargs={'max_retries': 20, 'inc_retry_interval': True, 'retry_interval': 1, 'max_retry_interval': 10}, _backend_mapping={'sqlalchemy': 'cinder.db.sqlalchemy.api'}, _backend_name='sqlalchemy', use_db_reconnect=False, get_by_id=<instancemethod at remote 0x7fb1f61d8050>, volume_type_get=<instancemethod at remote 0x7fb1f61c0f50>) at remote 0x7fb2003aab10>, target_mapping={'tgtadm': 'cinder.volume.t...(truncated) self.driver.check_for_setup_error() #58 Frame 0x3d15cf0, for file ./cinderlib-client.py, line 210, in load_backend (args=<Namespace(driver='{"volume_backend_name":"ceph- storage-ssd-ovirt","volume---Type <return> to continue, or q <return> to quit--- _driver":"cinder.volume.drivers.rbd.RBDDriver","rbd_ceph_conf":"/et c/ce ph/ceph.conf","rbd_user":"ovirt","rbd_keyring_conf":"/etc/ceph/ceph .cli ent.ovirt.keyring","rbd_pool":"storage- ssd","use_multipath_for_image_xfer":"true"}', db_url='postgresql+psycopg2://ovirt_cinderlib:ViRsNB3Dnwy5wmL0lLuDE q@lo calhost:5432/ovirt_cinderlib', correlation_id='7733e7cc', command=<function at remote 0x7fb1f52725f0>, volume_id='9d858d39- bbd4- 4cbe-9f2c-5bef25ed0525', connector_info='{"ip":null,"host":"compute00.hq.tnp.infra","os_type ":"l inux2","platform":"x86_64","initiator":"iqn.1994- 05.com.redhat:c6ab662d439c","multipath":true,"do_local_attach":fals e}') at remote 0x7fb1f5215910>, persistence_config={'connection': 'postgresql+psycopg2://ovirt_cinderlib:ViRsNB3Dnwy5wmL0lLuDEq@local host :5432/ovirt_cinderlib', 'storage': 'db'}) Python Exception <type 'exceptions.IOError'> [Errno 2] No such file or directory: './cinderlib-client.py': Error occurred in Python command: [Errno 2] No such file or directory: './cinderlib-client.py'
________________________________
The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England & Wales with company number: 07667393
This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e-mail if you have received this e-mail by mistake and delete this e-mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
________________________________ The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England & Wales with company number: 07667393 This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e-mail if you have received this e-mail by mistake and delete this e-mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
Is it possible to migrate existing vms to managed block storage? We do not have OVF support or stuff like that for MBS domains, you can attach MBS disks to existing VMs Or do you mean moving/copying existing disks to an MBS domain? in this case
No problem :) the answer is unfortunately no
Also is it possible to host the hosted engine on this storage? Unfortunately no
On Tue, Jul 9, 2019 at 4:57 PM Dan Poltawski <dan.poltawski@tnp.net.uk> wrote:
On Tue, 2019-07-09 at 11:12 +0300, Benny Zlotnik wrote:
VM live migration is supported and should work Can you add engine and cinderlib logs?
Sorry - looks like once again this was a misconfig by me on the ceph side..
Is it possible to migrate existing vms to managed block storage? Also is it possible to host the hosted engine on this storage?
Thanks Again for your help,
Dan
On Tue, Jul 9, 2019 at 11:01 AM Dan Poltawski < dan.poltawski@tnp.net.uk> wrote:
On Tue, 2019-07-09 at 08:00 +0100, Dan Poltawski wrote:
I've now managed to succesfully create/mount/delete volumes!
However, I'm seeing live migrations stay stuck. Is this supported?
(gdb) py-list 345 client.conf_set('rados_osd_op_timeout', timeout) 346 client.conf_set('rados_mon_op_timeout', timeout) 347 client.conf_set('client_mount_timeout', timeout) 348 349 client.connect()
350 ioctx = client.open_ioctx(pool) 351 return client, ioctx 352 except self.rados.Error: 353 msg = _("Error connecting to ceph cluster.") 354 LOG.exception(msg) 355 client.shutdown()
(gdb) py-bt #15 Frame 0x3ea0e50, for file /usr/lib/python2.7/site- packages/cinder/volume/drivers/rbd.py, line 350, in _do_conn (pool='storage-ssd', remote=None, timeout=-1, name='ceph', conf='/etc/ceph/ceph.conf', user='ovirt', client=<rados.Rados at remote 0x7fb1f4f83a60>) ioctx = client.open_ioctx(pool) #20 Frame 0x3ea4620, for file /usr/lib/python2.7/site- packages/retrying.py, line 217, in call (self=<Retrying(_retry_on_exception=<function at remote 0x7fb1f4f23488>, _wait_exponential_max=1073741823, _wait_incrementing_start=0, stop=<function at remote 0x7fb1f4f23578>, _stop_max_attempt_number=5, _wait_incrementing_increment=100, _wait_random_max=1000, _retry_on_result=<instancemethod at remote 0x7fb1f51da550>, _stop_max_delay=100, _wait_fixed=1000, _wrap_exception=False, _wait_random_min=0, _wait_exponential_multiplier=1, wait=<function at remote 0x7fb1f4f23500>) at remote 0x7fb1f4f1ae90>, fn=<function at remote 0x7fb1f4f23668>, args=(None, None, None), kwargs={}, start_time=1562658179214, attempt_number=1) attempt = Attempt(fn(*args, **kwargs), attempt_number, False) #25 Frame 0x3e49d50, for file /usr/lib/python2.7/site- packages/cinder/utils.py, line 818, in _wrapper (args=(None, None, None), kwargs={}, r=<Retrying(_retry_on_exception=<function at remote 0x7fb1f4f23488>, _wait_exponential_max=1073741823, _wait_incrementing_start=0, stop=<function at remote 0x7fb1f4f23578>, _stop_max_attempt_number=5, _wait_incrementing_increment=100, _wait_random_max=1000, _retry_on_result=<instancemethod at remote 0x7fb1f51da550>, _stop_max_delay=100, _wait_fixed=1000, _wrap_exception=False, _wait_random_min=0, _wait_exponential_multiplier=1, wait=<function at remote 0x7fb1f4f23500>) at remote 0x7fb1f4f1ae90>) return r.call(f, *args, **kwargs) #29 Frame 0x7fb1f4f9a810, for file /usr/lib/python2.7/site- packages/cinder/volume/drivers/rbd.py, line 358, in _connect_to_rados (self=<RBDDriver(_target_names=[], rbd=<module at remote 0x7fb20583e830>, _is_replication_enabled=False, _execute=<function at remote 0x7fb2041242a8>, _active_config={'name': 'ceph', 'conf': '/etc/ceph/ceph.conf', 'user': 'ovirt'}, _active_backend_id=None, _initialized=False, db=<DBAPI(_backend=<module at remote 0x7fb203f8d520>, qos_specs_get=<instancemethod at remote 0x7fb1f677d460>, _lock=<Semaphore(counter=1, _waiters=<collections.deque at remote 0x7fb1f5246d70>) at remote 0x7fb1f5205bd0>, _wrap_db_kwargs={'max_retries': 20, 'inc_retry_interval': True, 'retry_interval': 1, 'max_retry_interval': 10}, _backend_mapping={'sqlalchemy': 'cinder.db.sqlalchemy.api'}, _backend_name='sqlalchemy', use_db_reconnect=False, get_by_id=<instancemethod at remote 0x7fb1f61d8050>, volume_type_get=<instancemethod at remote 0x7fb1f61c0f50>) at remote 0x7fb2003aab10>, target_mapping={'tgtadm': 'cinder.vol...(truncated) return _do_conn(pool, remote, timeout) #33 Frame 0x7fb1f4f5b220, for file /usr/lib/python2.7/site- packages/cinder/volume/drivers/rbd.py, line 177, in __init__ (self=<RADOSClient(driver=<RBDDriver(_target_names=[], rbd=<module at remote 0x7fb20583e830>, _is_replication_enabled=False, _execute=<function at remote 0x7fb2041242a8>, _active_config={'name': 'ceph', 'conf': '/etc/ceph/ceph.conf', 'user': 'ovirt'}, _active_backend_id=None, _initialized=False, db=<DBAPI(_backend=<module at remote 0x7fb203f8d520>, qos_specs_get=<instancemethod at remote 0x7fb1f677d460>, _lock=<Semaphore(counter=1, _waiters=<collections.deque at remote 0x7fb1f5246d70>) at remote 0x7fb1f5205bd0>, _wrap_db_kwargs={'max_retries': 20, 'inc_retry_interval': True, 'retry_interval': 1, 'max_retry_interval': 10}, _backend_mapping={'sqlalchemy': 'cinder.db.sqlalchemy.api'}, _backend_name='sqlalchemy', use_db_reconnect=False, get_by_id=<instancemethod at remote 0x7fb1f61d8050>, volume_type_get=<instancemethod at remote 0x7fb1f61c0f50>) at remote 0x7fb2003aab10>, target_mapping={'tgtadm': ...(truncated) self.cluster, self.ioctx = driver._connect_to_rados(pool) #44 Frame 0x7fb1f4f9a620, for file /usr/lib/python2.7/site- packages/cinder/volume/drivers/rbd.py, line 298, in check_for_setup_error (self=<RBDDriver(_target_names=[], rbd=<module at remote 0x7fb20583e830>, _is_replication_enabled=False, _execute=<function at remote 0x7fb2041242a8>, _active_config={'name': 'ceph', 'conf': '/etc/ceph/ceph.conf', 'user': 'ovirt'}, _active_backend_id=None, _initialized=False, db=<DBAPI(_backend=<module at remote 0x7fb203f8d520>, qos_specs_get=<instancemethod at remote 0x7fb1f677d460>, _lock=<Semaphore(counter=1, _waiters=<collections.deque at remote 0x7fb1f5246d70>) at remote 0x7fb1f5205bd0>, _wrap_db_kwargs={'max_retries': 20, 'inc_retry_interval': True, 'retry_interval': 1, 'max_retry_interval': 10}, _backend_mapping={'sqlalchemy': 'cinder.db.sqlalchemy.api'}, _backend_name='sqlalchemy', use_db_reconnect=False, get_by_id=<instancemethod at remote 0x7fb1f61d8050>, volume_type_get=<instancemethod at remote 0x7fb1f61c0f50>) at remote 0x7fb2003aab10>, target_mapping={'tgtadm': 'cinder...(truncated) with RADOSClient(self): #48 Frame 0x3e5bef0, for file /usr/lib/python2.7/site- packages/cinderlib/cinderlib.py, line 88, in __init__ (self=<Backend(driver=<RBDDriver(_target_names=[], rbd=<module at remote 0x7fb20583e830>, _is_replication_enabled=False, _execute=<function at remote 0x7fb2041242a8>, _active_config={'name': 'ceph', 'conf': '/etc/ceph/ceph.conf', 'user': 'ovirt'}, _active_backend_id=None, _initialized=False, db=<DBAPI(_backend=<module at remote 0x7fb203f8d520>, qos_specs_get=<instancemethod at remote 0x7fb1f677d460>, _lock=<Semaphore(counter=1, _waiters=<collections.deque at remote 0x7fb1f5246d70>) at remote 0x7fb1f5205bd0>, _wrap_db_kwargs={'max_retries': 20, 'inc_retry_interval': True, 'retry_interval': 1, 'max_retry_interval': 10}, _backend_mapping={'sqlalchemy': 'cinder.db.sqlalchemy.api'}, _backend_name='sqlalchemy', use_db_reconnect=False, get_by_id=<instancemethod at remote 0x7fb1f61d8050>, volume_type_get=<instancemethod at remote 0x7fb1f61c0f50>) at remote 0x7fb2003aab10>, target_mapping={'tgtadm': 'cinder.volume.t...(truncated) self.driver.check_for_setup_error() #58 Frame 0x3d15cf0, for file ./cinderlib-client.py, line 210, in load_backend (args=<Namespace(driver='{"volume_backend_name":"ceph- storage-ssd-ovirt","volume---Type <return> to continue, or q <return> to quit--- _driver":"cinder.volume.drivers.rbd.RBDDriver","rbd_ceph_conf":"/et c/ce ph/ceph.conf","rbd_user":"ovirt","rbd_keyring_conf":"/etc/ceph/ceph .cli ent.ovirt.keyring","rbd_pool":"storage- ssd","use_multipath_for_image_xfer":"true"}', db_url='postgresql+psycopg2://ovirt_cinderlib:ViRsNB3Dnwy5wmL0lLuDE q@lo calhost:5432/ovirt_cinderlib', correlation_id='7733e7cc', command=<function at remote 0x7fb1f52725f0>, volume_id='9d858d39- bbd4- 4cbe-9f2c-5bef25ed0525', connector_info='{"ip":null,"host":"compute00.hq.tnp.infra","os_type ":"l inux2","platform":"x86_64","initiator":"iqn.1994- 05.com.redhat:c6ab662d439c","multipath":true,"do_local_attach":fals e}') at remote 0x7fb1f5215910>, persistence_config={'connection': 'postgresql+psycopg2://ovirt_cinderlib:ViRsNB3Dnwy5wmL0lLuDEq@local host :5432/ovirt_cinderlib', 'storage': 'db'}) Python Exception <type 'exceptions.IOError'> [Errno 2] No such file or directory: './cinderlib-client.py': Error occurred in Python command: [Errno 2] No such file or directory: './cinderlib-client.py'
________________________________
The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England & Wales with company number: 07667393
This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e-mail if you have received this e-mail by mistake and delete this e-mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
________________________________
The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England & Wales with company number: 07667393
This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e-mail if you have received this e-mail by mistake and delete this e-mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
Hi, On Sun, 2019-07-07 at 09:31 +0300, Benny Zlotnik wrote:
Any chance you can setup gdb[1] so we can find out where it's stuck exactly?
Yes, abolutely - but I will need some assistance in getting GDB configured in the engine as I am not very familar with it - or how to enable the correct repos to get the debug info. $ gdb python 54654 [...] Reading symbols from /lib64/libfreeblpriv3.so...Reading symbols from /lib64/libfreeblpriv3.so...(no debugging symbols found)...done. (no debugging symbols found)...done. Loaded symbols for /lib64/libfreeblpriv3.so 0x00007fcf82256483 in epoll_wait () from /lib64/libc.so.6 Missing separate debuginfos, use: debuginfo-install python-2.7.5- 80.el7_6.x86_64 (gdb) pt-bt Undefined command: "pt-bt". Try "help".
Also, which version of ovirt are you using?
Using 4.3.4
Can you also check the ceph logs for anything suspicious?
I haven't seen anything so far, but is an entirely resonable possibility this is ceph misoconfiguraiton as we are learning about both tools. thanks, Dan
[1] - https://wiki.python.org/moin/DebuggingWithGdb $ gdb python <cinderlib pid> then `py-bt`
On Thu, Jul 4, 2019 at 7:00 PM <dan.poltawski@tnp.net.uk> wrote:
Can you provide logs? mainly engine.log and cinderlib.log (/var/log/ovirt-engine/cinderlib/cinderlib.log
If I create two volumes, the first one succeeds successfully, the second one hangs. If I look in the processlist after creating the second volume which doesn't succceed, I see the python ./cinderlib- client.py create_volume [...] command still running.
On the ceph side, I can see only the one rbd volume.
Logs below:
--- cinderlib.log --
2019-07-04 16:46:30,863 - cinderlib-client - INFO - Fetch backend stats [b07698bb-1688-472f-841b-70a9d52a250d] 2019-07-04 16:46:56,308 - cinderlib-client - INFO - Creating volume '236285cc-ac01-4239-821c-4beadd66923f', with size '2' GB [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] 2019-07-04 16:47:21,671 - cinderlib-client - INFO - Creating volume '84886485-554a-44ca-964c-9758b4a16aae', with size '2' GB [a793bfc9- fc37-4711-a144-d74c100cc75b]
--- engine.log ---
2019-07-04 16:46:54,062+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80- ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:46:54,150+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator- Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:46:56,863+01 INFO [org.ovirt.engine.core.common.utils.cinderlib.CinderlibExecutor] (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] cinderlib output: 2019-07-04 16:46:56,912+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirect or] (default task-22) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:00,126+01 INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback ] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] Command 'AddDisk' id: '15fe157d-7adb- 4031-9e81-f51aa0b6528f' child commands '[d056397a-7ed9-4c01-b880- dd518421a2c6]' executions were completed, status 'SUCCEEDED' 2019-07-04 16:47:01,136+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f-cb20- 440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' successfully. 2019-07-04 16:47:01,141+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand] (EE-ManagedThreadFactory-engineScheduled- Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand' successfully. 2019-07-04 16:47:01,145+01 WARN [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- ManagedThreadFactory-engineScheduled-Thread-99) [] VM is null - no unlocking 2019-07-04 16:47:01,186+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirect or] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:19,446+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80- ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:47:19,464+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator- Thread-2) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'commandCoordinator' is using 1 threads out of 10, 1 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 9 threads waiting for tasks and 0 tasks in queue. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 threads waiting for tasks.
2019-07-04 16:46:54,062+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80- ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:46:54,150+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator- Thread-1) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:46:56,863+01 INFO [org.ovirt.engine.core.common.utils.cinderlib.CinderlibExecutor] (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] cinderlib output: 2019-07-04 16:46:56,912+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirect or] (default task-22) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:00,126+01 INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback ] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [0b0f0d6f- cb20-440a-bacb-7f5ead2b4b4d] Command 'AddDisk' id: '15fe157d-7adb- 4031-9e81-f51aa0b6528f' child commands '[d056397a-7ed9-4c01-b880- dd518421a2c6]' executions were completed, status 'SUCCEEDED' 2019-07-04 16:47:01,136+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- ManagedThreadFactory-engineScheduled-Thread-99) [0b0f0d6f-cb20- 440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' successfully. 2019-07-04 16:47:01,141+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand] (EE-ManagedThreadFactory-engineScheduled- Thread-99) [0b0f0d6f-cb20-440a-bacb-7f5ead2b4b4d] Ending command 'org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand' successfully. 2019-07-04 16:47:01,145+01 WARN [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE- ManagedThreadFactory-engineScheduled-Thread-99) [] VM is null - no unlocking 2019-07-04 16:47:01,186+01 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirect or] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'test0' was successfully added. 2019-07-04 16:47:19,446+01 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (default task-22) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddDiskCommand internal: false. Entities affected : ID: 31536d80- ff45-496b-9820-15441d505924 Type: StorageAction group CREATE_DISK with role type USER 2019-07-04 16:47:19,464+01 INFO [org.ovirt.engine.core.bll.storage.disk.managedblock.AddManagedBloc kStorageDiskCommand] (EE-ManagedThreadFactory-commandCoordinator- Thread-2) [a793bfc9-fc37-4711-a144-d74c100cc75b] Running command: AddManagedBlockStorageDiskCommand internal: true. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'commandCoordinator' is using 1 threads out of 10, 1 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 9 threads waiting for tasks and 0 tasks in queue. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks. 2019-07-04 16:48:19,501+01 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE- ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 threads waiting for tasks. _______________________________________________ Users mailing list -- users@ovirt.org To unsubscribe send an email to users-leave@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/VW5AZHXGU2YTSB...
________________________________ The Networking People (TNP) Limited. Registered office: Network House, Caton Rd, Lancaster, LA1 3PE. Registered in England & Wales with company number: 07667393 This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e-mail if you have received this e-mail by mistake and delete this e-mail from your system. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited.
participants (3)
-
Benny Zlotnik -
Dan Poltawski -
dan.poltawski＠tnp.net.uk