Skip to content

Cloud Usage consume loads of system resource in 4.20.1 #11127

Closed
Closed
Cloud Usage consume loads of system resource in 4.20.1#11127
Labels
component:usage-servertype:performance
Milestone
unplanned

Description

@levindecaro
levindecaro
opened on Jul 3, 2025

problem

After upgrading from 4.19.1 to 4.20.1, the cloud usage service and database continuously consume a significant amount of resources. The cloud usage consumes approximately 1 virtual CPU, 1.2 GB of memory, and database consumes 1 virtual CPU with 3.2 GB of memory. They never went down, additionally, the database bin log grows by 5 GB every day.

versions

ACS: 4.20.1
OS: OL9 x86_64
hypervisors: KVM
storage: NFS(SharedMountPoint)
network: vxlan

The steps to reproduce the bug

  1. Upgrade from 4.19.1 to 4.20.1
  2. Observe system resource usage

What to do about it?

Need to find a way to optimize the system usage.

Activity

  1. levindecaro
    closed this as completedon Jul 3, 2025

  2. DaanHoogland commented on Jul 3, 2025

    @DaanHoogland
    DaanHoogland
    on Jul 3, 2025
    Contributor

    Any story to tell about this @levindecaro ?

  3. levindecaro commented on Jul 3, 2025

    @levindecaro
    levindecaro
    on Jul 3, 2025
    ContributorAuthor

    @DaanHoogland I seems found something about duplicate db entry from usage.log, i’m trying to clear all error before reopening this issue, stay tune.

    2025-07-03 07:55:43,070 ERROR [cloud.usage.UsageManagerImpl_EnhancerByCloudStack_10d8ae6e] (Usage-Job-1:[]) (logid:) Exception in usage manager com.cloud.utils.exception.CloudRuntimeException: Duplicate entry '98-10-3003-643-1751414399999' for key 'PRIMARY'
        at com.cloud.usage.dao.UsageNetworkDaoImpl.saveUsageNetworks(UsageNetworkDaoImpl.java:128)
        at com.cloud.usage.dao.UsageNetworkDaoImpl_EnhancerByCloudStack_cbc98d7d.CGLIB$saveUsageNetworks$2(<generated>)
        at com.cloud.usage.dao.UsageNetworkDaoImpl_EnhancerByCloudStack_cbc98d7d_FastClassByCloudStack_113c6676.invoke(<generated>)
        at net.sf.cglib.proxy.MethodProxy.invokeSuper(MethodProxy.java:228)
        at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:123)
        at com.cloud.usage.dao.UsageNetworkDaoImpl_EnhancerByCloudStack_cbc98d7d.saveUsageNetworks(<generated>)
        at com.cloud.usage.UsageManagerImpl.parse(UsageManagerImpl.java:778)
        at com.cloud.usage.UsageManagerImpl.runInContextInternal(UsageManagerImpl.java:442)
        at com.cloud.usage.UsageManagerImpl$1.runInContext(UsageManagerImpl.java:379)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
        at com.cloud.usage.UsageManagerImpl.run(UsageManagerImpl.java:381)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
        at java.base/java.lang.Thread.run(Thread.java:840)

  4. levindecaro commented on Jul 3, 2025

    @levindecaro
    levindecaro
    on Jul 3, 2025
    ContributorAuthor

    @DaanHoogland is it safe to truncate all table in cloud_usage db?

  5. DaanHoogland commented on Jul 4, 2025

    @DaanHoogland
    DaanHoogland
    on Jul 4, 2025
    Contributor

    all table in cloud_usage db?

    why all? it would re-generate everything which could take a long time. I would not do that unless you first found the usage_event that caused the duplicate.

  6. levindecaro commented on Jul 7, 2025

    @levindecaro
    levindecaro
    on Jul 7, 2025
    ContributorAuthor

    @DaanHoogland just gave a try on truncate all tables, it has been ran for 3 days and the cpu went up once i got this error

    2025-07-07 08:24:47,835 ERROR [cloud.usage.UsageManagerImpl_EnhancerByCloudStack_10d8ae6e] (Usage-Job-1:[]) (logid:) found entries for a vm running with id: 3419, which are not stopped. Ending them all...
2025-07-07 08:24:47,846 ERROR [usage.dao.UsageVMInstanceDaoImpl_EnhancerByCloudStack_2cbdde2b] (Usage-Job-1:[]) (logid:) DB Exception on: HikariProxyPreparedStatement@416132582 wrapping com.mysql.cj.jdbc.ServerPreparedStatement[8719]: INSERT INTO usage_vm_instance (usage_vm_instance.usage_type, usage_vm_instance.zone_id, usage_vm_instance.account_id, usage_vm_instance.vm_instance_id, usage_vm_instance.vm_name, usage_vm_instance.service_offering_id, usage_vm_instance.cpu_cores, usage_vm_instance.memory, usage_vm_instance.cpu_speed, usage_vm_instance.template_id, usage_vm_instance.hypervisor_type, usage_vm_instance.start_date, usage_vm_instance.end_date) VALUES (1, 10, 137, 3419, x'4353434d', 23, NULL, NULL, NULL, 477, x'4b564d', '2024-03-18 02:58:28', NULL) java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '3419-1-2024-03-18 02:58:28' for key 'vm_instance_id'
        at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:118)
        at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122)
        at com.mysql.cj.jdbc.ServerPreparedStatement.serverExecute(ServerPreparedStatement.java:555)
        at com.mysql.cj.jdbc.ServerPreparedStatement.executeInternal(ServerPreparedStatement.java:339)
        at com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdateInternal(ClientPreparedStatement.java:1061)
        at com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdateInternal(ClientPreparedStatement.java:1009)
        at com.mysql.cj.jdbc.ClientPreparedStatement.executeLargeUpdate(ClientPreparedStatement.java:1320)
        at com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdate(ClientPreparedStatement.java:994)
        at jdk.internal.reflect.GeneratedMethodAccessor48.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:569)
        at com.mysql.cj.jdbc.ha.MultiHostConnectionProxy$JdbcInterfaceProxy.invoke(MultiHostConnectionProxy.java:107)
        at com.mysql.cj.jdbc.ha.FailoverConnectionProxy$FailoverJdbcInterfaceProxy.invoke(FailoverConnectionProxy.java:98)
        at jdk.proxy2/jdk.proxy2.$Proxy50.executeUpdate(Unknown Source)
        at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61)
        at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java)
        at com.cloud.utils.db.GenericDaoBase.persist(GenericDaoBase.java:1625)
        at com.cloud.usage.dao.UsageVMInstanceDaoImpl_EnhancerByCloudStack_2cbdde2b.CGLIB$persist$70(<generated>)
        at com.cloud.usage.dao.UsageVMInstanceDaoImpl_EnhancerByCloudStack_2cbdde2b_FastClassByCloudStack_a7ffbe4a.invoke(<generated>)
        at net.sf.cglib.proxy.MethodProxy.invokeSuper(MethodProxy.java:228)
        at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:123)
        at com.cloud.usage.dao.UsageVMInstanceDaoImpl_EnhancerByCloudStack_2cbdde2b.persist(<generated>)
        at com.cloud.usage.UsageManagerImpl.populateDynamicComputeOfferingDetailsAndPersist(UsageManagerImpl.java:1395)
        at com.cloud.usage.UsageManagerImpl.createVMHelperEvent(UsageManagerImpl.java:1252)
        at com.cloud.usage.UsageManagerImpl.createHelperRecord(UsageManagerImpl.java:1072)
        at com.cloud.usage.UsageManagerImpl.parse(UsageManagerImpl.java:726)
        at com.cloud.usage.UsageManagerImpl.runInContextInternal(UsageManagerImpl.java:442)
        at com.cloud.usage.UsageManagerImpl$1.runInContext(UsageManagerImpl.java:379)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
        at com.cloud.usage.UsageManagerImpl.run(UsageManagerImpl.java:381)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
        at java.base/java.lang.Thread.run(Thread.java:840)

2025-07-07 08:24:49,333 ERROR [cloud.usage.UsageManagerImpl_EnhancerByCloudStack_10d8ae6e] (Usage-Job-1:[]) (logid:) Error saving usage instance for vm: 3419 javax.persistence.EntityExistsException: Entity already exists 
        at com.cloud.utils.db.GenericDaoBase.handleEntityExistsException(GenericDaoBase.java:891)
        at com.cloud.utils.db.GenericDaoBase.persist(GenericDaoBase.java:1664)
        at com.cloud.usage.dao.UsageVMInstanceDaoImpl_EnhancerByCloudStack_2cbdde2b.CGLIB$persist$70(<generated>)
        at com.cloud.usage.dao.UsageVMInstanceDaoImpl_EnhancerByCloudStack_2cbdde2b_FastClassByCloudStack_a7ffbe4a.invoke(<generated>)
        at net.sf.cglib.proxy.MethodProxy.invokeSuper(MethodProxy.java:228)
        at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:123)
        at com.cloud.usage.dao.UsageVMInstanceDaoImpl_EnhancerByCloudStack_2cbdde2b.persist(<generated>)
        at com.cloud.usage.UsageManagerImpl.populateDynamicComputeOfferingDetailsAndPersist(UsageManagerImpl.java:1395)
        at com.cloud.usage.UsageManagerImpl.createVMHelperEvent(UsageManagerImpl.java:1252)
        at com.cloud.usage.UsageManagerImpl.createHelperRecord(UsageManagerImpl.java:1072)
        at com.cloud.usage.UsageManagerImpl.parse(UsageManagerImpl.java:726)
        at com.cloud.usage.UsageManagerImpl.runInContextInternal(UsageManagerImpl.java:442)
        at com.cloud.usage.UsageManagerImpl$1.runInContext(UsageManagerImpl.java:379)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
        at com.cloud.usage.UsageManagerImpl.run(UsageManagerImpl.java:381)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
        at java.base/java.lang.Thread.run(Thread.java:840)
Caused by: java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '3419-1-2024-03-18 02:58:28' for key 'vm_instance_id'
        at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:118)
        at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122)
        at com.mysql.cj.jdbc.ServerPreparedStatement.serverExecute(ServerPreparedStatement.java:555)
        at com.mysql.cj.jdbc.ServerPreparedStatement.executeInternal(ServerPreparedStatement.java:339)
        at com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdateInternal(ClientPreparedStatement.java:1061)
        at com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdateInternal(ClientPreparedStatement.java:1009)
        at com.mysql.cj.jdbc.ClientPreparedStatement.executeLargeUpdate(ClientPreparedStatement.java:1320)
        at com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdate(ClientPreparedStatement.java:994)
        at jdk.internal.reflect.GeneratedMethodAccessor48.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:569)
        at com.mysql.cj.jdbc.ha.MultiHostConnectionProxy$JdbcInterfaceProxy.invoke(MultiHostConnectionProxy.java:107)
        at com.mysql.cj.jdbc.ha.FailoverConnectionProxy$FailoverJdbcInterfaceProxy.invoke(FailoverConnectionProxy.java:98)
        at jdk.proxy2/jdk.proxy2.$Proxy50.executeUpdate(Unknown Source)
        at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61)
        at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java)
        at com.cloud.utils.db.GenericDaoBase.persist(GenericDaoBase.java:1625)
        ... 23 more
  7. levindecaro
    reopened this on Jul 7, 2025

  8. DaanHoogland commented on Jul 7, 2025

    @DaanHoogland
    DaanHoogland
    on Jul 7, 2025
    Contributor

    "3419-1-2024-03-18 02:58:28” this is the event that would have a duplicate. You would find it in cloud.usage_events. It would be a START event, type 1. VM id 3419, and start time "2024-03-18 02:58:28”.

  9. DaanHoogland
    added
    component:usage-server
    type:performance
    on Jul 7, 2025
  10. apache
    locked and limited conversation to collaborators on Jul 7, 2025
  11. DaanHoogland
    converted this issue into a discussion #11157 on Jul 7, 2025
  12. DaanHoogland
    added this to the unplanned milestone on Sep 20, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    component:usage-servertype:performance

    Type

    No type

    Projects

    No projects

      Milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions