Alpha162 opened a new issue, #13906:
URL: https://github.com/apache/cloudstack/issues/13906
### 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.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
