UsageManagerImpl.parse() rewind to the oldest unprocessed usage event is unbounded
- Dominant language
- Java
- Stars
- 3.1k
- Forks
- 1.4k
- Avg merge
- 6d 19h
- Merged PRs (30d)
- 32
Description
### problem
Split out of #13399 at @DaanHoogland's request.
`UsageManagerImpl.parse()` correctly derives its start date from the last successful job:
```java
long lastSuccess = _usageJobDao.getLastJobSuccessDateMillis();
if (lastSuccess != 0) {
startDateMillis = lastSuccess + 1;
}
```
and then overwrites it with the create date of the oldest unprocessed event, moving it only ever *earlier*:
```java
// make sure start date is before all of our un-processed events
Date oldestEventDate = events.get(0).getCreateDate();
if (oldestEventDate.getTime() < startDateMillis) {
startDateMillis = oldestEventDate.getTime();
startDate = new Date(startDateMillis);
}
```
`events` comes from `UsageEventDaoImpl.listLatestEvents()` — `WHERE processed = 0 AND created <= ? ORDER BY createDate ASC`, with no limit and no floor.
**Consequence:** any event that can never be successfully processed pins the aggregation start date permanently. Each subsequent run re-aggregates from that date to the present, growing by one aggregation range per range elapsed. The job continues to report `success = 1` throughout, so nothing surfaces as an error.
Measured on an affected 4.22.1.0 deployment:
- **1,678** consecutive successful jobs whose `start_millis` never advanced past a single event 71 days earlier
- `exec_time` of **2,555,055 ms** (42.6 min) per *hourly* run, growing by 24 aggregation periods per day
- `cloud_usage` at **54.4M rows / 14 GB**, of which roughly 150k rows were genuine; duplicate counts were an exact multiple of the number of replays
**Not specific to one event type:** #13112 was reported on 4.21.0.0 against `usage_type = 13`, predating the volume-specific trigger in #13399. The rewind is the common mechanism; the triggering event type varies.
### versions
Observed on CloudStack 4.22.1.0 (EL9 packages), MySQL 8.x / InnoDB, with `usage.stats.job.aggregation.range = 60` and `usage.stats.job.exec.time = 00:15`.
#13112 reports the same mechanism on 4.21.0.0, so this is not new in 4.22.
### The steps to reproduce the bug
1. Have any row in `cloud_usage.usage_event` that cannot be successfully processed, #13399 gives one reliable route, but the mechanism is independent of cause.
2. Let the usage job run on its normal schedule.
3. `SELECT id, start_date, end_date, exec_time FROM cloud_usage.usage_job WHERE success = 1 ORDER BY id DESC LIMIT 5;` — `start_date` stays pinned at the oldest unprocessed event's `created` while `end_date` advances.
4. `TIMESTAMPDIFF(HOUR, start_date, end_date)` grows without bound, as does `exec_time`.
5. Row counts in `cloud_usage.cloud_usage` per period equal the number of times that period has been re-aggregated.
### What to do about it?
Bound the rewind, and/or provide a way to quarantine or age out events that repeatedly fail to process, so one unprocessable row cannot halt aggregation indefinitely.
This is a design decision rather than an obvious patch, which is why it's raised separately from #13399.
Contributor guide
Research direction
Start with UsageManagerImpl.parse() and UsageEventDaoImpl.listLatestEvents(), then inspect the usage_job and usage_event queries described in the issue. Reproduce the pinned start_date and growing aggregation range, and define a bounded rewind or event-quarantine behavior whose completion criteria include preventing one permanently unprocessed event from causing unbounded re-aggregation.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- java, mysql
- Domain
- backend, data, databases
- Issue type
- Bug
- Difficulty
- 5/5
- Estimated time
- Over a week
- Activity status
- Active
- Clarity
- Needs clarification
- Newbie friendliness
- 35/100