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 <[email protected]> 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 -- [email protected] > To unsubscribe send an email to [email protected] > 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/[email protected]/message/VW5AZHXGU2YTSBBYJI4YEUNBSI6CDXUS/ >
_______________________________________________ Users mailing list -- [email protected] To unsubscribe send an email to [email protected] 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/[email protected]/message/Q5KPHHXK36BBOKWKEPJOZOYMZ6VP2R3J/
