[ovirt-users] Re: Managed Block Storage

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.