Investigating `incus list` slowness
Is there an existing issue for this?
- [x] There is no existing issue for this bug
Is this happening on an up to date version of Incus?
- [x] This is happening on a supported version of Incus
Incus system details
config:
cluster.https_address: 10.77.0.22:8443
core.https_address: 10.77.0.22:8443
storage.linstor.controller_connection: sirius1-sto,sirius2-sto,sirius3-sto,sirius4-sto,sirius5-sto
storage.linstor.satellite.name: sirius2-sto
api_extensions:
- storage_zfs_remove_snapshots
- container_host_shutdown_timeout
- container_stop_priority
- container_syscall_filtering
- auth_pki
- container_last_used_at
- etag
- patch
- usb_devices
- https_allowed_credentials
- image_compression_algorithm
- directory_manipulation
- container_cpu_time
- storage_zfs_use_refquota
- storage_lvm_mount_options
- network
- profile_usedby
- container_push
- container_exec_recording
- certificate_update
- container_exec_signal_handling
- gpu_devices
- container_image_properties
- migration_progress
- id_map
- network_firewall_filtering
- network_routes
- storage
- file_delete
- file_append
- network_dhcp_expiry
- storage_lvm_vg_rename
- storage_lvm_thinpool_rename
- network_vlan
- image_create_aliases
- container_stateless_copy
- container_only_migration
- storage_zfs_clone_copy
- unix_device_rename
- storage_lvm_use_thinpool
- storage_rsync_bwlimit
- network_vxlan_interface
- storage_btrfs_mount_options
- entity_description
- image_force_refresh
- storage_lvm_lv_resizing
- id_map_base
- file_symlinks
- container_push_target
- network_vlan_physical
- storage_images_delete
- container_edit_metadata
- container_snapshot_stateful_migration
- storage_driver_ceph
- storage_ceph_user_name
- resource_limits
- storage_volatile_initial_source
- storage_ceph_force_osd_reuse
- storage_block_filesystem_btrfs
- resources
- kernel_limits
- storage_api_volume_rename
- network_sriov
- console
- restrict_dev_incus
- migration_pre_copy
- infiniband
- dev_incus_events
- proxy
- network_dhcp_gateway
- file_get_symlink
- network_leases
- unix_device_hotplug
- storage_api_local_volume_handling
- operation_description
- clustering
- event_lifecycle
- storage_api_remote_volume_handling
- nvidia_runtime
- container_mount_propagation
- container_backup
- dev_incus_images
- container_local_cross_pool_handling
- proxy_unix
- proxy_udp
- clustering_join
- proxy_tcp_udp_multi_port_handling
- network_state
- proxy_unix_dac_properties
- container_protection_delete
- unix_priv_drop
- pprof_http
- proxy_haproxy_protocol
- network_hwaddr
- proxy_nat
- network_nat_order
- container_full
- backup_compression
- nvidia_runtime_config
- storage_api_volume_snapshots
- storage_unmapped
- projects
- network_vxlan_ttl
- container_incremental_copy
- usb_optional_vendorid
- snapshot_scheduling
- snapshot_schedule_aliases
- container_copy_project
- clustering_server_address
- clustering_image_replication
- container_protection_shift
- snapshot_expiry
- container_backup_override_pool
- snapshot_expiry_creation
- network_leases_location
- resources_cpu_socket
- resources_gpu
- resources_numa
- kernel_features
- id_map_current
- event_location
- storage_api_remote_volume_snapshots
- network_nat_address
- container_nic_routes
- cluster_internal_copy
- seccomp_notify
- lxc_features
- container_nic_ipvlan
- network_vlan_sriov
- storage_cephfs
- container_nic_ipfilter
- resources_v2
- container_exec_user_group_cwd
- container_syscall_intercept
- container_disk_shift
- storage_shifted
- resources_infiniband
- daemon_storage
- instances
- image_types
- resources_disk_sata
- clustering_roles
- images_expiry
- resources_network_firmware
- backup_compression_algorithm
- ceph_data_pool_name
- container_syscall_intercept_mount
- compression_squashfs
- container_raw_mount
- container_nic_routed
- container_syscall_intercept_mount_fuse
- container_disk_ceph
- virtual-machines
- image_profiles
- clustering_architecture
- resources_disk_id
- storage_lvm_stripes
- vm_boot_priority
- unix_hotplug_devices
- api_filtering
- instance_nic_network
- clustering_sizing
- firewall_driver
- projects_limits
- container_syscall_intercept_hugetlbfs
- limits_hugepages
- container_nic_routed_gateway
- projects_restrictions
- custom_volume_snapshot_expiry
- volume_snapshot_scheduling
- trust_ca_certificates
- snapshot_disk_usage
- clustering_edit_roles
- container_nic_routed_host_address
- container_nic_ipvlan_gateway
- resources_usb_pci
- resources_cpu_threads_numa
- resources_cpu_core_die
- api_os
- container_nic_routed_host_table
- container_nic_ipvlan_host_table
- container_nic_ipvlan_mode
- resources_system
- images_push_relay
- network_dns_search
- container_nic_routed_limits
- instance_nic_bridged_vlan
- network_state_bond_bridge
- usedby_consistency
- custom_block_volumes
- clustering_failure_domains
- resources_gpu_mdev
- console_vga_type
- projects_limits_disk
- network_type_macvlan
- network_type_sriov
- container_syscall_intercept_bpf_devices
- network_type_ovn
- projects_networks
- projects_networks_restricted_uplinks
- custom_volume_backup
- backup_override_name
- storage_rsync_compression
- network_type_physical
- network_ovn_external_subnets
- network_ovn_nat
- network_ovn_external_routes_remove
- tpm_device_type
- storage_zfs_clone_copy_rebase
- gpu_mdev
- resources_pci_iommu
- resources_network_usb
- resources_disk_address
- network_physical_ovn_ingress_mode
- network_ovn_dhcp
- network_physical_routes_anycast
- projects_limits_instances
- network_state_vlan
- instance_nic_bridged_port_isolation
- instance_bulk_state_change
- network_gvrp
- instance_pool_move
- gpu_sriov
- pci_device_type
- storage_volume_state
- network_acl
- migration_stateful
- disk_state_quota
- storage_ceph_features
- projects_compression
- projects_images_remote_cache_expiry
- certificate_project
- network_ovn_acl
- projects_images_auto_update
- projects_restricted_cluster_target
- images_default_architecture
- network_ovn_acl_defaults
- gpu_mig
- project_usage
- network_bridge_acl
- warnings
- projects_restricted_backups_and_snapshots
- clustering_join_token
- clustering_description
- server_trusted_proxy
- clustering_update_cert
- storage_api_project
- server_instance_driver_operational
- server_supported_storage_drivers
- event_lifecycle_requestor_address
- resources_gpu_usb
- clustering_evacuation
- network_ovn_nat_address
- network_bgp
- network_forward
- custom_volume_refresh
- network_counters_errors_dropped
- metrics
- image_source_project
- clustering_config
- network_peer
- linux_sysctl
- network_dns
- ovn_nic_acceleration
- certificate_self_renewal
- instance_project_move
- storage_volume_project_move
- cloud_init
- network_dns_nat
- database_leader
- instance_all_projects
- clustering_groups
- ceph_rbd_du
- instance_get_full
- qemu_metrics
- gpu_mig_uuid
- event_project
- clustering_evacuation_live
- instance_allow_inconsistent_copy
- network_state_ovn
- storage_volume_api_filtering
- image_restrictions
- storage_zfs_export
- network_dns_records
- storage_zfs_reserve_space
- network_acl_log
- storage_zfs_blocksize
- metrics_cpu_seconds
- instance_snapshot_never
- certificate_token
- instance_nic_routed_neighbor_probe
- event_hub
- agent_nic_config
- projects_restricted_intercept
- metrics_authentication
- images_target_project
- images_all_projects
- cluster_migration_inconsistent_copy
- cluster_ovn_chassis
- container_syscall_intercept_sched_setscheduler
- storage_lvm_thinpool_metadata_size
- storage_volume_state_total
- instance_file_head
- instances_nic_host_name
- image_copy_profile
- container_syscall_intercept_sysinfo
- clustering_evacuation_mode
- resources_pci_vpd
- qemu_raw_conf
- storage_cephfs_fscache
- network_load_balancer
- vsock_api
- instance_ready_state
- network_bgp_holdtime
- storage_volumes_all_projects
- metrics_memory_oom_total
- storage_buckets
- storage_buckets_create_credentials
- metrics_cpu_effective_total
- projects_networks_restricted_access
- storage_buckets_local
- loki
- acme
- internal_metrics
- cluster_join_token_expiry
- remote_token_expiry
- init_preseed
- storage_volumes_created_at
- cpu_hotplug
- projects_networks_zones
- network_txqueuelen
- cluster_member_state
- instances_placement_scriptlet
- storage_pool_source_wipe
- zfs_block_mode
- instance_generation_id
- disk_io_cache
- amd_sev
- storage_pool_loop_resize
- migration_vm_live
- ovn_nic_nesting
- oidc
- network_ovn_l3only
- ovn_nic_acceleration_vdpa
- cluster_healing
- instances_state_total
- auth_user
- security_csm
- instances_rebuild
- numa_cpu_placement
- custom_volume_iso
- network_allocations
- zfs_delegate
- storage_api_remote_volume_snapshot_copy
- operations_get_query_all_projects
- metadata_configuration
- syslog_socket
- event_lifecycle_name_and_project
- instances_nic_limits_priority
- disk_initial_volume_configuration
- operation_wait
- image_restriction_privileged
- cluster_internal_custom_volume_copy
- disk_io_bus
- storage_cephfs_create_missing
- instance_move_config
- ovn_ssl_config
- certificate_description
- disk_io_bus_virtio_blk
- loki_config_instance
- instance_create_start
- clustering_evacuation_stop_options
- boot_host_shutdown_action
- agent_config_drive
- network_state_ovn_lr
- image_template_permissions
- storage_bucket_backup
- storage_lvm_cluster
- shared_custom_block_volumes
- auth_tls_jwt
- oidc_claim
- device_usb_serial
- numa_cpu_balanced
- image_restriction_nesting
- network_integrations
- instance_memory_swap_bytes
- network_bridge_external_create
- network_zones_all_projects
- storage_zfs_vdev
- container_migration_stateful
- profiles_all_projects
- instances_scriptlet_get_instances
- instances_scriptlet_get_cluster_members
- instances_scriptlet_get_project
- network_acl_stateless
- instance_state_started_at
- networks_all_projects
- network_acls_all_projects
- storage_buckets_all_projects
- resources_load
- instance_access
- project_access
- projects_force_delete
- resources_cpu_flags
- disk_io_bus_cache_filesystem
- instance_oci
- clustering_groups_config
- instances_lxcfs_per_instance
- clustering_groups_vm_cpu_definition
- disk_volume_subpath
- projects_limits_disk_pool
- network_ovn_isolated
- qemu_raw_qmp
- network_load_balancer_health_check
- oidc_scopes
- network_integrations_peer_name
- qemu_scriptlet
- instance_auto_restart
- storage_lvm_metadatasize
- ovn_nic_promiscuous
- ovn_nic_ip_address_none
- instances_state_os_info
- network_load_balancer_state
- instance_nic_macvlan_mode
- storage_lvm_cluster_create
- network_ovn_external_interfaces
- instances_scriptlet_get_instances_count
- cluster_rebalance
- custom_volume_refresh_exclude_older_snapshots
- storage_initial_owner
- storage_live_migration
- instance_console_screenshot
- image_import_alias
- authorization_scriptlet
- console_force
- network_ovn_state_addresses
- network_bridge_acl_devices
- instance_debug_memory
- init_preseed_storage_volumes
- init_preseed_profile_project
- instance_nic_routed_host_address
- instance_smbios11
- api_filtering_extended
- acme_dns01
- security_iommu
- network_ipv4_dhcp_routes
- network_state_ovn_ls
- network_dns_nameservers
- acme_http01_port
- network_ovn_ipv4_dhcp_expiry
- instance_state_cpu_time
- network_io_bus
- disk_io_bus_usb
- storage_driver_linstor
- instance_oci_entrypoint
- network_address_set
- server_logging
- network_forward_snat
- memory_hotplug
- instance_nic_routed_host_tables
- instance_publish_split
- init_preseed_certificates
- custom_volume_sftp
- network_ovn_external_nic_address
- network_physical_gateway_hwaddr
- backup_s3_upload
- snapshot_manual_expiry
- resources_cpu_address_sizes
api_status: stable
api_version: "1.0"
auth: trusted
public: false
auth_methods:
- tls
auth_user_name: ben
auth_user_method: unix
environment:
addresses:
- 10.77.0.22:8443
architectures:
- x86_64
- i686
certificate: |
-----BEGIN CERTIFICATE-----
MIICATCCAYegAwIBAgIRAPvVKKmUPo6EN8MgBK/irhkwCgYIKoZIzj0EAwMwMjEZ
MBcGA1UEChMQTGludXggQ29udGFpbmVyczEVMBMGA1UEAwwMcm9vdEBzaXJpdXMz
MB4XDTI1MDQwOTE2NDQyN1oXDTM1MDQwNzE2NDQyN1owMjEZMBcGA1UEChMQTGlu
dXggQ29udGFpbmVyczEVMBMGA1UEAwwMcm9vdEBzaXJpdXMzMHYwEAYHKoZIzj0C
AQYFK4EEACIDYgAEIRqCK6ll6/MlzXi8xCbF4B4LlwYfmfVYWklL3y5IYhEZua8U
cXkk0Jwo9dn3vbje/z0pzYSfuB2WWX1nP+l1sw5OnJcYKHLK9I2tfa57F6BsHu8K
BGlDHjTq5TLkL4nvo2EwXzAOBgNVHQ8BAf8EBAMCBaAwEwYDVR0lBAwwCgYIKwYB
BQUHAwEwDAYDVR0TAQH/BAIwADAqBgNVHREEIzAhggdzaXJpdXMzhwR/AAABhxAA
AAAAAAAAAAAAAAAAAAABMAoGCCqGSM49BAMDA2gAMGUCMQCKiGTHIXdjjZyle/u+
nrLEBGm3BnrqnywGBsFNXkWVgxamWBTyd3kvsYPivvEY3qkCMA5wz+hQAhzgM3B0
kJQTLJHd9elWbuZ1BX82R4R3jE2rLjlHjWhmdIw5JzOsj4ez3Q==
-----END CERTIFICATE-----
certificate_fingerprint: c8132b2fc62d7ea88642e4eb0699c7e983aa8e729b8699121c84d03518e26850
driver: lxc | qemu
driver_version: 6.0.4 | 9.0.4
firewall: nftables
kernel: Linux
kernel_architecture: x86_64
kernel_features:
idmapped_mounts: "true"
netnsid_getifaddrs: "true"
seccomp_listener: "true"
seccomp_listener_continue: "true"
uevent_injection: "true"
unpriv_binfmt: "false"
unpriv_fscaps: "true"
kernel_version: 6.1.0-34-amd64
lxc_features:
cgroup2: "true"
core_scheduling: "true"
devpts_fd: "true"
idmapped_mounts_v2: "true"
mount_injection_file: "true"
network_gateway_device_route: "true"
network_ipvlan: "true"
network_l2proxy: "true"
network_phys_macvlan_mtu: "true"
network_veth_router: "true"
pidfd: "true"
seccomp_allow_deny_syntax: "true"
seccomp_notify: "true"
seccomp_proxy_send_notify_fd: "true"
os_name: Debian GNU/Linux
os_version: "12"
project: default
server: incus
server_clustered: true
server_event_mode: full-mesh
server_name: sirius2
server_pid: 416908
server_version: "6.14"
storage: zfs | linstor
storage_version: 2.1.11-1+deb12u1 | 1.31.3 / 9.2.13
storage_supported_drivers:
- name: dir
version: "1"
remote: false
- name: zfs
version: 2.1.11-1+deb12u1
remote: false
- name: linstor
version: 1.31.3 / 9.2.13
remote: true
Instance details
No response
Instance log
No response
Current behavior
incus list can be very slow at times. On my production environment (5-node cluster, 48 CT, 6 VM), incus list takes 5 to 6 s on average. I’ve setup a lab to reproduce the issue and have found out that:
- VMs are the main source of slowdown
- Tuning https://github.com/lxc/incus/blob/2af5cc1b208552db94d867287f078d6ec27af4cf/cmd/incusd/instances_get.go#L373 to a higher maximum value can help
- VMs being started / whose agent doesn’t yet answer are a huge source of slowdown
My testing lab has 32 images:debian/trixie stock containers and 16 images:debian/trixie stock VMs.
4 threads, VMs started
# hyperfine --warmup 2 'incus list'
Benchmark 1: incus list
Time (mean ± σ): 505.8 ms ± 7.5 ms [User: 40.2 ms, System: 25.5 ms]
Range (min … max): 493.3 ms … 513.1 ms 10 runs
16 threads, VMs started
# hyperfine --warmup 2 'incus list'
Benchmark 1: incus list
Time (mean ± σ): 372.3 ms ± 3.9 ms [User: 43.6 ms, System: 16.4 ms]
Range (min … max): 363.8 ms … 377.7 ms 10 runs
16 threads, VMs starting
# hyperfine --warmup 2 'incus list'
Benchmark 1: incus list
Time (mean ± σ): 1.184 s ± 0.262 s [User: 0.060 s, System: 0.070 s]
Range (min … max): 0.963 s … 1.897 s 10 runs
Expected behavior
No response
Steps to reproduce
Just have a production environment with a few VMs.
I managed to pinpoint another source of slowness in my production environment. router2 is running on sirius5.
On sirius2,
root@sirius2:~# while true; do /usr/bin/time -f%es sh -c 'incus query /1.0/instances/router2?recursion=1 > /dev/null'; done
0.11s
3.23s
0.10s
0.10s
3.23s
0.10s
0.10s
3.24s
3.23s
3.23s
On sirius5,
root@sirius5:~# while true; do /usr/bin/time -f%es sh -c 'incus query /1.0/instances/router2?recursion=1 > /dev/null'; done
0.10s
0.10s
0.09s
0.09s
0.09s
0.09s
0.09s
0.10s
0.09s
0.10s
Network is not the problem here. Running incusd with --debug shows that the request flows from sirius2 to sirius5, sirius5 shows an immediate-ish result (compatible with the 0.10s measurements), but Incus lacks a “hey, I’ve received some JSON from the remote I just contacted” message, so my debugging stops there.
Note that this is the only instance that behaves this way in the whole infra, but in the meantime, I don’t see how the problem could be instance-related, because the debug logs show the JSON on the remote side.
@bensmrs were you able to put more debug statements in place to try to pinpoint exactly what's being slow? I'm also assuming this is still happening and we didn't accidentally fixed this in the past couple of releases.
FWIW, I just looked at both my production clusters they both have around 100 instances total across several projects with about a 50/50 split between containers and VMs.
I'm getting a pretty consistent 1.2s time for a full incus list --all-projects but worth noting that I'm doing this from a laptop on wifi over a VPN and using OIDC authentication ;)
@bensmrs were you able to put more debug statements in place to try to pinpoint exactly what's being slow? I'm also assuming this is still happening and we didn't accidentally fixed this in the past couple of releases.
Yeah, still happening. That’s a tough one because it’s really visible on my production environment, but reproducing a similar workload on a testing environment is quite hard. Best I can do is probe the production environment without actively patching the Incus daemon. I don’t think I’m doing anything wild, although I should be one of the lucky few to do the SR-IOV+LINSTOR combo. If it’s relevant, most of our containers were migrated from libvirt between 1 and 2 years ago.
I'm getting a pretty consistent 1.2s time for a full incus list --all-projects but worth noting that I'm doing this from a laptop on wifi over a VPN and using OIDC authentication ;)
Lucky you. 6–7 seconds here is really frustrating :)
Anyway, I think you can reproduce the case where the VMs are starting and their agent doesn’t answer; it should give you a noticeable slowdown.
You can try to set core.debug_address and then get a dump from /debug/pprof/goroutines?debug=2 during the 3s delay.
That should show you everything Incus is doing at the time and hopefully let us narrow down where it's stuck.
You can try to set core.debug_address and then get a dump from /debug/pprof/goroutines?debug=2 during the 3s delay.
Sure, I’ll do that, probably on Thursday. That’ll only help with the bug I noticed on Sep 30th, but it’s a good start.
Yeah, the case where the VM agent is jammed is a bit trickier.
If not running at all (VM is booting or can't run the agent), the failure should be very quick as it won't have notified the host that the agent is ready through the serial console. But if it did notify us that the agent is ready but then doesn't answer or is jammed, at that point we need to hit a timeout...
I don't remember exactly how that stuff works, but if we have some kind of in-memory state to tell us that the agent is supposed to be running, hitting a timeout should probably clear that at least.
It won't really help much with hostile VMs, but that's what the agent metrics config is for, setting that to false should make it always be instant, just with poorer data.
I wrote a tiny profiler that computes successive diffs in pprof outputs after reducing their entropy a bit -> https://gist.github.com/bensmrs/6ee6ee17e2d7c705e328f00dbaa02314
Here are the outputs (2 different runs, don’t try to programmatically correlate them!) on sirius2 (the server that runs the incus query) and sirius5 (the server that has the instance) when a request takes 3 seconds. You can use your favorite diff viewer and navigate through the files, that represent diffs in running goroutines from one measurement to the other.
LMK if that helps. I’m not sure I’ll have much time to debug it today.
I am having a similar problem. I don't have a minimum reproducible case but I do have an observation. I deleted a STOPPED VM (Alpine/3.22 from images:) and a FROZEN VM (debinan/13 from images: I believe) and now listing is fast. I wonder if Incus is attempting to contact the incus-agent on a frozen VM and has to wait until it times out...
I think pausing has something to do with it. I paused another VM and the time to list went back up to 4s+. I resumed it and the time to list went back down to 0.1s.
Ah, well if it's an issue because of pause VMs, that should be easy to fix. That would likely be different from @bensmrs' issue then though.
Yeah it’s very different, but I feel like one mega-issue to sort everything slow in incus list is also good :)
(plus I explicitly invited them to post here)
https://github.com/lxc/incus/pull/2747 has the fix for the paused case