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.