Usage Server repeatedly reprocesses historical usage and creates duplicate cloud_usage records for usage_type=1

problem

We are experiencing what appears to be the same issue described in #13112, however in our environment it affects usage_type = 1 (default VM usage) instead of the usage type reported in the original issue.
The Usage Server repeatedly reprocesses historical usage records from a fixed timestamp and continuously inserts duplicate records into the cloud_usage table.

observed behaviour

The Usage Server repeatedly processes the same historical records and generates duplicate rows in cloud_usage.

start date repeatedly reprocessed: 2026-05-29T22:00:00+0200

relation to #13112

This issue appears very similar to #13112.

Differences:

Apache CloudStack Usage Server repeatedly reprocesses historical usage from fixed start date and creates duplicate cloud_usage records #13112 reported the problem for usage_type = 13
We observe the same behaviour for usage_type = 1
The issue was reported as fixed in a later CloudStack release by the original Poster, however we are running 4.22.1.0 which is newer than the reported version.

Because the symptoms are effectively identical, it indicates that the issue still persists in newer versions.

evidence

Relevant Usage Server logs:

During the period where duplicate usage records are generated, the Usage Server repeatedly processes historical time ranges and emits SQL integrity constraint violations.
A log snippet is attached. VM and account names have been redacted from the logs for data protection purposes.

_usage.2026-05-28.log

A representative example is shown below:
2026-05-29 23:15:00,005 INFO Parsing usage records between [2026-05-29T20:00:00+0000] and [2026-05-29T20:59:59+0000] ERROR: Duplicate entry '570-2026-05-29 20:50:40' for key 'id' java.sql.SQLIntegrityConstraintViolationException WARN: Failed to create usage event id: 1703940 type: VOLUME.CREATE due to Entity already exists
The exception indicates that the Usage Server is attempting to insert records that already exist. This appears to coincide with the repeated processing of historical usage intervals and the continuous growth of duplicate usage records described above.

To quantify the issue, we wrote a Python script that hashes usage records and counts identical entries for a single virtual machine grouped by hour.
The expected result is exactly one record per hourly interval (count = 1).
This expectation is met until 2026-05-29 22:00, after which duplicate records begin appearing. The duplication follows a distinct pattern:

2026-05-29 22:00 → 204 identical records
2026-05-29 23:00 → 203 identical records
2026-05-30 00:00 → 202 identical records
2026-05-30 01:00 → 201 identical records

The pattern continues with each subsequent hourly bucket containing one fewer duplicate than the previous bucket.
This suggests that historical usage intervals are being repeatedly regenerated or reprocessed by the Usage Server. While the total number of records continues to increase over time, the number of duplicates associated with each successive hourly interval decreases by one.
Example output for a single VM:

{
"2026-05-29": {
"21": 1,
"22": 204,
"23": 203
},
"2026-05-30": {
"00": 202,
"01": 201,
"02": 200,
"03": 199
}
}

versions

OS: Ubuntu 24.04.4 LTS
Hypervisor: KVM, libvirt 10.0.0-2ubuntu8.13
Database: MariaDB 10.11.14-MariaDB-0ubuntu0.24.04.1-log Ubuntu 24.04
CloudStack: 4.22.1.0

The steps to reproduce the bug

The exact trigger is currently unknown. In our environment, the issue can be observed with the following setup:

Enable the Usage Server in Apache CloudStack.
Configure:
- usage.stats.job.aggregation.range = 60
- usage.stats.job.exec.time = 00:15
Allow the Usage Server to run normally for an extended period.
Observe the cloud_usage table and Usage Server logs.
Duplicate usage records begin appearing and continue to accumulate over time.

What to do about it?

One observation that might be relevant, is a start-timestamp on 2026-05-29 at 20:00:14 (UTC). This is the only differing usage record. All other duplicates are exactly the same (within VM, day and hour) and their start-timestamps are all for second "00". Without knowing the actual contexts, it does look as if this one existing usage record for second "14" kind of congests the system now. Meaning the server did create an entry for second "14". At the same time it tried to create an entry for second "00". This failed due to the constraint-violation by having the same ID as the entry for second "14". This is observable in the logs.

Starting the following hour the system is indeed creating entries for all subsequent usage records including the one for the timestamp in question. But somehow maybe because of this one "failed" entry, the system does not recognize all subsequently created entries as valid/processed and recreates all of them again every hour.

Thanks for opening your first issue here! Be sure to follow the issue template!

We had the same issue on several stage and prod environments. Her are our findings and solution to it.
You see that start_date of the usage_job is stuck.

SELECT * FROM ( SELECT * FROM cloud_usage.usage_job ORDER BY id DESC LIMIT 10 ) sub ORDER BY id ASC; +-------+------------------------------------+--------+----------+-----------+---------------+---------------+-----------+---------------------+---------------------+---------+---------------------+ | id | host | pid | job_type | scheduled | start_millis | end_millis | exec_time | start_date | end_date | success | heartbeat | +-------+------------------------------------+--------+----------+-----------+---------------+---------------+-----------+---------------------+---------------------+---------+---------------------+ | 52246 | mgmt-stage1.proio.local/127.0.1.1 | 1353 | 0 | 0 | 1781690455000 | 1784365199999 | 25095596 | 2026-06-17 10:00:55 | 2026-07-18 08:59:59 | 1 | 2026-07-18 16:13:25 | | 52247 | mgmt-stage1.proio.local/127.0.1.1 | 1353 | 0 | 0 | 1781690455000 | 1784390399999 | 25288347 | 2026-06-17 10:00:55 | 2026-07-18 15:59:59 | 1 | 2026-07-18 23:14:25 | | 52248 | mgmt-stage1.proio.local/127.0.1.1 | 1353 | 0 | 0 | 1781690455000 | 1784415599999 | 25566185 | 2026-06-17 10:00:55 | 2026-07-18 22:59:59 | 1 | 2026-07-19 06:21:25 | | 52249 | mgmt-stage1.proio.local/127.0.1.1 | 1353 | 0 | 0 | 1781690455000 | 1784440799999 | 25793951 | 2026-06-17 10:00:55 | 2026-07-19 05:59:59 | 1 | 2026-07-19 13:31:25 | | 52250 | mgmt-stage1.proio.local/127.0.1.1 | 1353 | 0 | 0 | 1781690455000 | 1784465999999 | 26110859 | 2026-06-17 10:00:55 | 2026-07-19 12:59:59 | 1 | 2026-07-19 20:46:25 | | 52251 | mgmt-stage1.proio.local/127.0.1.1 | 1353 | 0 | 0 | 1781690455000 | 1784491199999 | 26317753 | 2026-06-17 10:00:55 | 2026-07-19 19:59:59 | 1 | 2026-07-20 04:04:25 | | 52252 | mgmt-stage1.proio.local/127.0.1.1 | 1353 | 0 | 0 | 1781690455000 | 1784519999999 | 26624851 | 2026-06-17 10:00:55 | 2026-07-20 03:59:59 | 1 | 2026-07-20 11:28:25 | | 52256 | mgmt-stage1.proio.local/127.0.1.1 | 916185 | 0 | 0 | 0 | 0 | 0 | NULL | NULL | NULL | 2026-07-20 14:59:10 | +-------+------------------------------------+--------+----------+-----------+---------------+---------------+-----------+---------------------+---------------------+---------+---------------------+

The reason it is stuck is that we had unprocessed usage_events.

SELECT id, type, resource_id, created, processed FROM usage_event WHERE processed = 0; +--------+---------------------+-------------+---------------------+-----------+ | id | type | resource_id | created | processed | +--------+---------------------+-------------+---------------------+-----------+ | 481831 | BACKUP.USAGE.METRIC | 40 | 2026-06-17 10:00:55 | 0 | | 481903 | VOLUME.CREATE | 1897 | 2026-06-17 10:26:15 | 0 | +--------+---------------------+-------------+---------------------+-----------+

To get usage back on track and using the correct start_date, we needed to set processed to 1.

UPDATE usage_event SET processed = 1 WHERE processed = 0

The next usage run was working as expected.

@mwa-sudo

@mwa-sudo , is @sbrueseke ’s workaround useful for you?

@DaanHoogland

@mwa-sudo , is @sbrueseke ’s workaround useful for you?

@DaanHoogland it looks like this workaround is only a temporary fix. After some days of normal usage running, the issue is back with another start_date hanging. We restarted our investigation. This happened to both ACS installations we fixed with this workaround.

@mwa-sudo

@mwa-sudo , is @sbrueseke ’s workaround useful for you?

@DaanHoogland sorry, I can't tell. Since we couldn't rely on the usage data for our billing, we ended up disabling the Usage Server entirely. Instead, we now use the API and custom scripts to fetch the data we need. We would still be very interested in a reliable fix.

What we see after the second time using the workaround is the following:

 SELECT * FROM ( SELECT * FROM cloud_usage.usage_job ORDER BY id DESC LIMIT 10 ) sub ORDER BY id ASC;
+-------+------------------------------------+---------+----------+-----------+---------------+---------------+-----------+---------------------+---------------------+---------+---------------------+
| id    | host                               | pid     | job_type | scheduled | start_millis  | end_millis    | exec_time | start_date          | end_date            | success | heartbeat           |
+-------+------------------------------------+---------+----------+-----------+---------------+---------------+-----------+---------------------+---------------------+---------+---------------------+
| 52470 | pc-cm-1.fra1.proio.local/127.0.1.1 |  916185 |        0 |         0 | 1784797248000 | 1785376799999 |   5744828 | 2026-07-23 09:00:48 | 2026-07-30 01:59:59 |       1 | 2026-07-30 03:42:10 |
| 52471 | pc-cm-1.fra1.proio.local/127.0.1.1 |  916185 |        0 |         0 | 1784797248000 | 1785380399999 |   5772631 | 2026-07-23 09:00:48 | 2026-07-30 02:59:59 |       1 | 2026-07-30 05:19:10 |
| 52472 | pc-cm-1.fra1.proio.local/127.0.1.1 |  916185 |        0 |         0 | 1784797248000 | 1785387599999 |   5861548 | 2026-07-23 09:00:48 | 2026-07-30 04:59:59 |       1 | 2026-07-30 06:56:10 |
| 52473 | pc-cm-1.fra1.proio.local/127.0.1.1 |  916185 |        0 |         0 | 1784797248000 | 1785391199999 |   5861860 | 2026-07-23 09:00:48 | 2026-07-30 05:59:59 |       1 | 2026-07-30 08:34:10 |
| 52475 | pc-cm-1.fra1.proio.local/127.0.1.1 | 1817733 |        0 |         0 | 1785391200000 | 1785398399999 |     22701 | 2026-07-30 06:00:00 | 2026-07-30 07:59:59 |       0 | 2026-07-30 08:39:36 |
| 52476 | pc-cm-1.fra1.proio.local/127.0.1.1 | 1817733 |        0 |         0 | 1785391200000 | 1785398399999 |     22347 | 2026-07-30 06:00:00 | 2026-07-30 07:59:59 |       0 | 2026-07-30 08:40:36 |
| 52477 | pc-cm-1.fra1.proio.local/127.0.1.1 | 1817733 |        0 |         0 | 1785391200000 | 1785398399999 |     22082 | 2026-07-30 06:00:00 | 2026-07-30 07:59:59 |       0 | 2026-07-30 08:41:36 |
| 52478 | pc-cm-1.fra1.proio.local/127.0.1.1 | 1817733 |        0 |         0 | 1785391200000 | 1785398399999 |     22321 | 2026-07-30 06:00:00 | 2026-07-30 07:59:59 |       0 | 2026-07-30 08:42:36 |
| 52479 | pc-cm-1.fra1.proio.local/127.0.1.1 | 1817733 |        0 |         0 | 1785391200000 | 1785398399999 |     22058 | 2026-07-30 06:00:00 | 2026-07-30 07:59:59 |       0 | 2026-07-30 08:43:36 |
| 52480 | pc-cm-1.fra1.proio.local/127.0.1.1 | 1817733 |        0 |         0 |             0 |             0 |         0 | NULL                | NULL                |    NULL | 2026-07-30 08:43:58 |
+-------+------------------------------------+---------+----------+-----------+---------------+---------------+-----------+---------------------+---------------------+---------+---------------------+
10 rows in set (0.00 sec)

After the next scheduled run of usage, success is 1.

SELECT * FROM ( SELECT * FROM cloud_usage.usage_job ORDER BY id DESC LIMIT 10 ) sub ORDER BY id ASC;
+-------+------------------------------------+---------+----------+-----------+---------------+---------------+-----------+---------------------+---------------------+---------+---------------------+
| id    | host                               | pid     | job_type | scheduled | start_millis  | end_millis    | exec_time | start_date          | end_date            | success | heartbeat           |
+-------+------------------------------------+---------+----------+-----------+---------------+---------------+-----------+---------------------+---------------------+---------+---------------------+
| 52488 | pc-cm-1.fra1.proio.local/127.0.1.1 | 1817733 |        0 |         0 | 1785391200000 | 1785398399999 |     22004 | 2026-07-30 06:00:00 | 2026-07-30 07:59:59 |       0 | 2026-07-30 08:52:36 |
| 52489 | pc-cm-1.fra1.proio.local/127.0.1.1 | 1817733 |        0 |         0 | 1785391200000 | 1785398399999 |     21922 | 2026-07-30 06:00:00 | 2026-07-30 07:59:59 |       0 | 2026-07-30 08:53:36 |
| 52490 | pc-cm-1.fra1.proio.local/127.0.1.1 | 1817733 |        0 |         0 | 1785391200000 | 1785398399999 |     21983 | 2026-07-30 06:00:00 | 2026-07-30 07:59:59 |       0 | 2026-07-30 08:54:36 |
| 52491 | pc-cm-1.fra1.proio.local/127.0.1.1 | 1817733 |        0 |         0 | 1785391200000 | 1785398399999 |     22038 | 2026-07-30 06:00:00 | 2026-07-30 07:59:59 |       0 | 2026-07-30 08:55:36 |
| 52492 | pc-cm-1.fra1.proio.local/127.0.1.1 | 1817733 |        0 |         0 | 1785391200000 | 1785398399999 |     22093 | 2026-07-30 06:00:00 | 2026-07-30 07:59:59 |       0 | 2026-07-30 08:56:36 |
| 52493 | pc-cm-1.fra1.proio.local/127.0.1.1 | 1817733 |        0 |         0 | 1785391200000 | 1785398399999 |     22033 | 2026-07-30 06:00:00 | 2026-07-30 07:59:59 |       0 | 2026-07-30 08:57:36 |
| 52494 | pc-cm-1.fra1.proio.local/127.0.1.1 | 1817733 |        0 |         0 | 1785391200000 | 1785398399999 |     21968 | 2026-07-30 06:00:00 | 2026-07-30 07:59:59 |       0 | 2026-07-30 08:58:36 |
| 52495 | pc-cm-1.fra1.proio.local/127.0.1.1 | 1817733 |        0 |         0 | 1785391200000 | 1785398399999 |     22006 | 2026-07-30 06:00:00 | 2026-07-30 07:59:59 |       0 | 2026-07-30 08:59:36 |
| 52496 | pc-cm-1.fra1.proio.local/127.0.1.1 | 1817733 |        0 |         0 | 1785391200000 | 1785401999999 |    163559 | 2026-07-30 06:00:00 | 2026-07-30 08:59:59 |       1 | 2026-07-30 09:02:36 |
| 52497 | pc-cm-1.fra1.proio.local/127.0.1.1 | 1817733 |        0 |         0 |             0 |             0 |         0 | NULL                | NULL                |    NULL | 2026-07-30 09:09:36 |
+-------+------------------------------------+---------+----------+-----------+---------------+---------------+-----------+---------------------+---------------------+---------+---------------------+
10 rows in set (0.00 sec)

@sbrueseke

anything you did between 2026-07-30 08:59:36 and 2026-07-30 09:02:36, @sbrueseke ?
also, it suddenly processes a 3 hour window instead of a 2 hour one??? and for some reason that is successful?

@DaanHoogland

anything you did between 2026-07-30 08:59:36 and 2026-07-30 09:02:36, @sbrueseke ? also, it suddenly processes a 3 hour window instead of a 2 hour one??? and for some reason that is successful?

@DaanHoogland no, not that we are aware of.

@DaanHoogland

@DaanHoogland both raised:

GenericDaoBase.persist() leaves the caller's transaction unbalanced when an insert throws #13905
UsageManagerImpl.parse() rewind to the oldest unprocessed usage event is unbounded #13906

I couldn't attach them as sub-issues, that needs write/triage on the repo which I don't have, so they're standalone for now. Happy for you or anyone with permissions to link them under this one.

Schema PR to follow, option 1 as discussed.

@Alpha162

@Alpha162 reading back your earlier message, I think you may need the combination of options 1 and 2 as we are changing keys in the cloud_usage scheme.

usage: widen usage_volume unique key to include vm_id

@DaanHoogland

@DaanHoogland understood, I'll add usage.idempotent_drop_unique_key.sql and usage.idempotent_add_unique_key.sql under db/procedures/ as cloud_usage-schema copies of the cloud versions, and have the migration call those instead. Keeps cloud_usage DDL going through cloud_usage procedures like the rest of the file. PR shortly.

usage: add IDEMPOTENT_ADD_UNIQUE_KEY procedure for cloud_usage schema

usage: add IDEMPOTENT_DROP_UNIQUE_KEY procedure for cloud_usage schema

usage: call the cloud_usage idempotent key procedures

@DaanHoogland

PR is up: #13909

Adds the two cloud_usage-schema procedures and has the migration call those, per your last comment @DaanHoogland.

One thing I flagged in the PR description rather than deciding myself: CONTRIBUTING.md says bug fixes should target a release branch, which would be 4.22 — but 4.22 has no 4.22.1 → 4.22.2 upgrade path yet (its newest is Upgrade42200to42210.java), whereas main already has Upgrade42210to42300.java. Creating a 4.22.2 path seemed like a release-management call rather than mine, so I targeted main.

If it ought to live in 4.22 instead, a cherry-pick or retarget by someone familiar with the release process would be safer than me creating a 4.22.2 upgrade path from scratch, happy to follow guidance if that's the route.

🎯 Triage report

Usage Server repeatedly reprocesses historical usage intervals and inserts duplicate cloud_usage rows due to a unique-key/constraint-violation loop, affecting usage_type=1 (VM usage) on 4.22.1.0. This is a well-documented variant of #13112. Root cause has since been identified in the comment thread (a defect introduced by #11531 around createVolumeHelperEvent handling), and a fix PR (#13909, with supporting DB migration issues #13905/#13906) is already up.

📊 Assessment

Dimension	Value	Reasoning
Type	type:bug	Reproducible defect causing data corruption in usage accounting
Component	component:usage-server	Issue is entirely within Usage Server processing/DB schema
Severity	Severity:Major	Corrupts billing data and requires disabling the Usage Server as a workaround, but is not a full outage
Labels	type:bug, component:usage-server, Severity:Major	See above
Coding agent	Not suitable	Root cause analysis and fix are already in progress by a human contributor with PR #13909 open

🔗 Similar issues

Apache CloudStack Usage Server repeatedly reprocesses historical usage from fixed start date and creates duplicate cloud_usage records #13112 — related, same duplicate-usage-record symptom for a different usage_type, referenced directly in this issue

💡 Notes and suggestions

The issue thread already contains a thorough root-cause analysis (constraint violation on cloud_usage/usage_event due to a non-idempotent volume-create usage event) and a fix is in review via PR #13909. Maintainers should track this issue against that PR and close both #13905/#13906 as resolved once #13909 merges. No further action needed from triage beyond linking.

Generated by Daily Issue Triage · sonnet50 224.8K · ◷

Add this agentic workflows to your repo

To install this agentic workflow, run

gh aw add githubnext/agentics/workflows/daily-issue-triage.md@d7c1dc4b72b00607a67caaffdcc216cb64379cf9

@waterWang

💡 Notes and suggestions
The issue thread already contains a thorough root-cause analysis (constraint violation on cloud_usage/usage_event due to a non-idempotent volume-create usage event) and a fix is in review via PR #13909. Maintainers should track this issue against that PR and close both #13905/#13906 as resolved once #13909 merges. No further action needed from triage beyond linking.

these remarks by the bot are misleading, the sub-issues are not solved by the index adjustment. @waterWang’s PRs are, but need back porting to older LTS branches.

Navigation Menu

Repository navigation

Usage Server repeatedly reprocesses historical usage and creates duplicate cloud_usage records for usage_type=1 #13399

problem

observed behaviour

relation to #13112

evidence

versions

The steps to reproduce the bug

What to do about it?

13 remaining items

🎯 Triage report

📊 Assessment

🔗 Similar issues

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Usage Server repeatedly reprocesses historical usage and creates duplicate cloud_usage records for usage_type=1 #13399

Description

problem

observed behaviour

relation to #13112

evidence

versions

The steps to reproduce the bug

What to do about it?

Activity

boring-cyborg commented on Jun 11, 2026

sbrueseke commented on Jul 21, 2026

DaanHoogland commented on Jul 22, 2026

sbrueseke commented on Jul 30, 2026

mwa-sudo commented on Jul 30, 2026

sbrueseke commented on Jul 30, 2026

sbrueseke commented on Jul 30, 2026

DaanHoogland commented on Jul 30, 2026

sbrueseke commented on Jul 30, 2026

13 remaining items

Alpha162 commented on Aug 18, 2026

DaanHoogland commented on Aug 18, 2026

Alpha162 commented on Aug 18, 2026

Alpha162 commented on Aug 18, 2026

github-actions commented on Aug 20, 2026

🎯 Triage report

📊 Assessment

🔗 Similar issues

DaanHoogland commented on Aug 21, 2026

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions