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/VW5AZHXGU2YTSBBYJI4YEUNBSI6CDXUS/