incus icon indicating copy to clipboard operation
incus copied to clipboard

Investigating `incus list` slowness

Open bensmrs opened this issue 5 months ago • 8 comments

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.

bensmrs avatar Jul 22 '25 16:07 bensmrs

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 avatar Sep 30 '25 12:09 bensmrs

@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.

stgraber avatar Nov 09 '25 06:11 stgraber

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 ;)

stgraber avatar Nov 09 '25 06:11 stgraber

@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.

bensmrs avatar Nov 09 '25 13:11 bensmrs

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.

stgraber avatar Nov 09 '25 19:11 stgraber

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.

bensmrs avatar Nov 09 '25 19:11 bensmrs

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.

stgraber avatar Nov 09 '25 19:11 stgraber

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.

diffs.tgz

LMK if that helps. I’m not sure I’ll have much time to debug it today.

bensmrs avatar Nov 13 '25 10:11 bensmrs

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...

mkgvt avatar Dec 10 '25 18:12 mkgvt

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.

mkgvt avatar Dec 10 '25 18:12 mkgvt

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.

stgraber avatar Dec 10 '25 20:12 stgraber

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)

bensmrs avatar Dec 10 '25 21:12 bensmrs

https://github.com/lxc/incus/pull/2747 has the fix for the paused case

stgraber avatar Dec 11 '25 02:12 stgraber