apache / apache/cloudstack

UsageManagerImpl.parse() rewind to the oldest unprocessed usage event is unbounded

Open
#13,906 1 comment 0 reactions 0 assignees View on GitHub
bug
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

Open the contributing 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

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.