| Line 1... |
Line 1... |
| 1 |
package com.smartdukaan.cron.monitored;
|
1 |
package com.smartdukaan.cron.monitored;
|
| 2 |
|
2 |
|
| - |
|
3 |
import java.time.LocalDate;
|
| 3 |
import java.util.Map;
|
4 |
import java.util.Map;
|
| 4 |
import java.util.concurrent.ConcurrentHashMap;
|
5 |
import java.util.concurrent.ConcurrentHashMap;
|
| 5 |
import java.util.concurrent.atomic.AtomicInteger;
|
6 |
import java.util.concurrent.atomic.AtomicInteger;
|
| 6 |
import java.util.concurrent.atomic.AtomicLong;
|
7 |
import java.util.concurrent.atomic.AtomicLong;
|
| 7 |
|
8 |
|
| Line 38... |
Line 39... |
| 38 |
* number, not a health one. Do not alert on it alone.
|
39 |
* number, not a health one. Do not alert on it alone.
|
| 39 |
*
|
40 |
*
|
| 40 |
* Rates are deliberately NOT published. solved/shown and dates/answered are one division
|
41 |
* Rates are deliberately NOT published. solved/shown and dates/answered are one division
|
| 41 |
* in PromQL and storing them would freeze the numerator and denominator apart.
|
42 |
* in PromQL and storing them would freeze the numerator and denominator apart.
|
| 42 |
*
|
43 |
*
|
| 43 |
* -1 means "no pass has finished since this JVM started", so a scrape before the first
|
44 |
* -1 means "no day has been cleared since this JVM started", so a scrape before the first
|
| 44 |
* run is distinguishable from a genuine zero -- same convention as {@link BalanceGauges}.
|
45 |
* tick is distinguishable from a genuine zero -- same convention as {@link BalanceGauges}.
|
| - |
|
46 |
*
|
| - |
|
47 |
* ⚠ The gauges are registered lazily, on the first tick that names a brand. After a
|
| - |
|
48 |
* restart the whole imei_activation_* family is therefore ABSENT from /actuator/prometheus
|
| - |
|
49 |
* rather than reading -1, until each lane takes its first turn. Under the old midnight
|
| - |
|
50 |
* cron that blind window could last most of a day; under a 20-second tick it is seconds.
|
| 45 |
*/
|
51 |
*/
|
| 46 |
@Component
|
52 |
@Component
|
| 47 |
public class ImeiActivationGauges {
|
53 |
public class ImeiActivationGauges {
|
| 48 |
|
54 |
|
| 49 |
private static final Logger LOGGER = LogManager.getLogger(ImeiActivationGauges.class);
|
55 |
private static final Logger LOGGER = LogManager.getLogger(ImeiActivationGauges.class);
|
| Line 55... |
Line 61... |
| 55 |
|
61 |
|
| 56 |
public ImeiActivationGauges(MeterRegistry meterRegistry) {
|
62 |
public ImeiActivationGauges(MeterRegistry meterRegistry) {
|
| 57 |
this.meterRegistry = meterRegistry;
|
63 |
this.meterRegistry = meterRegistry;
|
| 58 |
}
|
64 |
}
|
| 59 |
|
65 |
|
| - |
|
66 |
/**
|
| - |
|
67 |
* True while this brand has not yet opened today's funnel.
|
| - |
|
68 |
*
|
| - |
|
69 |
* The caller uses it to decide how much pool to fetch: on the day's first tick it
|
| - |
|
70 |
* needs the whole thing to have a denominator, on every later tick it needs only the
|
| - |
|
71 |
* next chunk. Asking here keeps that decision in one place rather than duplicating a
|
| - |
|
72 |
* date field per lane.
|
| - |
|
73 |
*/
|
| - |
|
74 |
public boolean needsDayStart(String brand) {
|
| - |
|
75 |
return !LocalDate.now().equals(funnel(brand).day);
|
| - |
|
76 |
}
|
| - |
|
77 |
|
| - |
|
78 |
/**
|
| - |
|
79 |
* Open a brand's funnel for today, with the pool size measured on the first tick.
|
| - |
|
80 |
*
|
| - |
|
81 |
* The unit used to be a pass -- one bounded run that began and ended inside a single
|
| 60 |
/** Called once at the start of a brand's daily pass, with the snapshotted pool size. */
|
82 |
* call. Ticks have no such boundary, so the DAY is the unit now: `due` is what was
|
| - |
|
83 |
* outstanding at the first tick after midnight, and everything else accumulates
|
| - |
|
84 |
* across the day's ticks until the pool comes back empty.
|
| - |
|
85 |
*
|
| - |
|
86 |
* Truncation is detected HERE rather than at the end of a run, because a day that
|
| - |
|
87 |
* ran out of hours never reaches endDay at all -- it just stops. Rolling over with
|
| - |
|
88 |
* yesterday still open is exactly that case, and it is the line worth alerting on.
|
| - |
|
89 |
*/
|
| 61 |
public void beginPass(String brand, int due) {
|
90 |
public void beginDay(String brand, int due) {
|
| 62 |
BrandFunnel f = funnel(brand);
|
91 |
BrandFunnel f = funnel(brand);
|
| - |
|
92 |
if (f.day != null && !f.finished) {
|
| - |
|
93 |
LOGGER.warn("[{}] {} ended without clearing: {} of {} imeis churned, the tail rolls into today",
|
| - |
|
94 |
brand, f.day, f.churned.get(), f.due.get());
|
| - |
|
95 |
}
|
| 63 |
f.reset(due);
|
96 |
f.reset(due);
|
| - |
|
97 |
f.day = LocalDate.now();
|
| - |
|
98 |
f.finished = false;
|
| 64 |
LOGGER.info("[{}] pass begin: {} imeis due", brand, due);
|
99 |
LOGGER.info("[{}] day begin: {} imeis due", brand, due);
|
| 65 |
}
|
100 |
}
|
| 66 |
|
101 |
|
| 67 |
/** A captcha widget rendered and is ready to be attacked. */
|
102 |
/** A captcha widget rendered and is ready to be attacked. */
|
| 68 |
public void captchaShown(String brand) {
|
103 |
public void captchaShown(String brand) {
|
| 69 |
funnel(brand).captchaShown.incrementAndGet();
|
104 |
funnel(brand).captchaShown.incrementAndGet();
|
| Line 96... |
Line 131... |
| 96 |
public void error(String brand) {
|
131 |
public void error(String brand) {
|
| 97 |
funnel(brand).errors.incrementAndGet();
|
132 |
funnel(brand).errors.incrementAndGet();
|
| 98 |
}
|
133 |
}
|
| 99 |
|
134 |
|
| 100 |
/**
|
135 |
/**
|
| - |
|
136 |
* Called the first time a brand's turn comes back with nothing due, which under a
|
| 101 |
* Called once when a brand's pass ends. Stamps the duration and the completion time,
|
137 |
* tick model is what "the day's work is cleared" means. Stamps the duration and the
|
| 102 |
* and logs the one line worth grepping for.
|
138 |
* completion time, and logs the one line worth grepping for.
|
| - |
|
139 |
*
|
| - |
|
140 |
* Idempotent by design: every later tick that day also finds an empty pool and calls
|
| - |
|
141 |
* this, and must stay silent. Silence is the point -- at a 20-second cadence a log
|
| - |
|
142 |
* line per idle tick is 4,320 lines a day per brand on a log that is already 1.8GB.
|
| - |
|
143 |
*
|
| - |
|
144 |
* lastFinishEpoch therefore becomes a genuine completion clock. It read -1 for three
|
| - |
|
145 |
* days straight under the old model, which said only "no pass has finished since this
|
| - |
|
146 |
* JVM started" and could not distinguish a truncated pass from a fresh restart.
|
| 103 |
*/
|
147 |
*/
|
| 104 |
public void endPass(String brand) {
|
148 |
public void endDay(String brand) {
|
| 105 |
BrandFunnel f = funnel(brand);
|
149 |
BrandFunnel f = funnel(brand);
|
| - |
|
150 |
if (!LocalDate.now().equals(f.day) || f.finished) {
|
| - |
|
151 |
return;
|
| - |
|
152 |
}
|
| - |
|
153 |
f.finished = true;
|
| 106 |
long seconds = (System.currentTimeMillis() - f.startedAtMillis) / 1000;
|
154 |
long seconds = (System.currentTimeMillis() - f.startedAtMillis) / 1000;
|
| 107 |
f.runSeconds.set(seconds);
|
155 |
f.runSeconds.set(seconds);
|
| 108 |
f.lastFinishEpoch.set(System.currentTimeMillis() / 1000);
|
156 |
f.lastFinishEpoch.set(System.currentTimeMillis() / 1000);
|
| 109 |
|
157 |
|
| 110 |
int shown = f.captchaShown.get();
|
158 |
int shown = f.captchaShown.get();
|
| 111 |
int solved = f.captchaSolved.get();
|
159 |
int solved = f.captchaSolved.get();
|
| 112 |
int answered = f.answered.get();
|
160 |
int answered = f.answered.get();
|
| 113 |
LOGGER.info("[{}] pass end: due={} churned={} captcha {}/{} ({}%) answered={} dates={} errors={} in {}s",
|
161 |
LOGGER.info("[{}] day cleared: due={} churned={} captcha {}/{} ({}%) answered={} dates={} errors={} in {}s",
|
| 114 |
brand, f.due.get(), f.churned.get(), solved, shown, percent(solved, shown),
|
162 |
brand, f.due.get(), f.churned.get(), solved, shown, percent(solved, shown),
|
| 115 |
answered, f.datesFound.get(), f.errors.get(), seconds);
|
163 |
answered, f.datesFound.get(), f.errors.get(), seconds);
|
| 116 |
|
164 |
|
| 117 |
if (f.churned.get() > 0 && answered == 0) {
|
165 |
if (f.churned.get() > 0 && answered == 0) {
|
| 118 |
LOGGER.error("[{}] pass answered NOTHING across {} imeis -- the brand is down, not merely unlucky",
|
166 |
LOGGER.error("[{}] answered NOTHING across {} imeis -- the brand is down, not merely unlucky",
|
| 119 |
brand, f.churned.get());
|
167 |
brand, f.churned.get());
|
| 120 |
}
|
168 |
}
|
| 121 |
if (f.churned.get() < f.due.get()) {
|
169 |
// churned short of due is normal now rather than a truncation: the pool is
|
| - |
|
170 |
// re-queried every tick, so anything another writer filled in mid-day (carlcare
|
| 122 |
LOGGER.warn("[{}] pass did not finish: {} of {} imeis churned, the tail rolls into tomorrow",
|
171 |
// and the DCR pull both write rows) leaves without this lane ever touching it.
|
| 123 |
brand, f.churned.get(), f.due.get());
|
172 |
// Real truncation is the day that never gets here at all, caught in beginDay.
|
| 124 |
}
|
- |
|
| 125 |
}
|
173 |
}
|
| 126 |
|
174 |
|
| 127 |
private static int percent(int part, int whole) {
|
175 |
private static int percent(int part, int whole) {
|
| 128 |
return whole == 0 ? 0 : (int) Math.round(100.0 * part / whole);
|
176 |
return whole == 0 ? 0 : (int) Math.round(100.0 * part / whole);
|
| 129 |
}
|
177 |
}
|
| Line 132... |
Line 180... |
| 132 |
return byBrand.computeIfAbsent(brand, b -> new BrandFunnel(meterRegistry, b));
|
180 |
return byBrand.computeIfAbsent(brand, b -> new BrandFunnel(meterRegistry, b));
|
| 133 |
}
|
181 |
}
|
| 134 |
|
182 |
|
| 135 |
/**
|
183 |
/**
|
| 136 |
* One brand's counters, registered against the meter registry the first time that
|
184 |
* One brand's counters, registered against the meter registry the first time that
|
| 137 |
* brand is seen. Gauges hold last-pass values rather than lifetime totals: these
|
185 |
* brand is seen. Gauges hold the CURRENT DAY's values rather than lifetime totals:
|
| 138 |
* passes run once a day, so "what did the last run do" is the question being asked,
|
186 |
* the question being asked is "how far has today got", and a lifetime counter cannot
|
| 139 |
* and a counter that only moves once a day is awkward to alert on.
|
187 |
* answer it. They climb across the day's ticks and reset at the first tick after
|
| - |
|
188 |
* midnight.
|
| 140 |
*/
|
189 |
*/
|
| 141 |
private static final class BrandFunnel {
|
190 |
private static final class BrandFunnel {
|
| 142 |
|
191 |
|
| 143 |
private final AtomicInteger due = new AtomicInteger(NOT_RUN_YET);
|
192 |
private final AtomicInteger due = new AtomicInteger(NOT_RUN_YET);
|
| 144 |
private final AtomicInteger churned = new AtomicInteger(NOT_RUN_YET);
|
193 |
private final AtomicInteger churned = new AtomicInteger(NOT_RUN_YET);
|
| Line 150... |
Line 199... |
| 150 |
private final AtomicLong runSeconds = new AtomicLong(NOT_RUN_YET);
|
199 |
private final AtomicLong runSeconds = new AtomicLong(NOT_RUN_YET);
|
| 151 |
private final AtomicLong lastFinishEpoch = new AtomicLong(NOT_RUN_YET);
|
200 |
private final AtomicLong lastFinishEpoch = new AtomicLong(NOT_RUN_YET);
|
| 152 |
|
201 |
|
| 153 |
private volatile long startedAtMillis = System.currentTimeMillis();
|
202 |
private volatile long startedAtMillis = System.currentTimeMillis();
|
| 154 |
|
203 |
|
| - |
|
204 |
/** The day this funnel is currently accumulating; null until the first tick ever. */
|
| - |
|
205 |
private volatile LocalDate day;
|
| - |
|
206 |
|
| - |
|
207 |
/** Whether that day's pool has already come back empty. Keeps endDay silent after the first. */
|
| - |
|
208 |
private volatile boolean finished;
|
| - |
|
209 |
|
| 155 |
BrandFunnel(MeterRegistry registry, String brand) {
|
210 |
BrandFunnel(MeterRegistry registry, String brand) {
|
| 156 |
Tags tags = Tags.of("brand", brand.toLowerCase());
|
211 |
Tags tags = Tags.of("brand", brand.toLowerCase());
|
| 157 |
gauge(registry, "imei_activation_due", tags, due,
|
212 |
gauge(registry, "imei_activation_due", tags, due,
|
| 158 |
"Imeis the last pass snapshotted for this brand; -1 = no pass yet");
|
213 |
"Imeis outstanding at the first tick after midnight; -1 = no tick yet");
|
| 159 |
gauge(registry, "imei_activation_churned", tags, churned,
|
214 |
gauge(registry, "imei_activation_churned", tags, churned,
|
| 160 |
"Imeis the last pass actually reached; short of due means it ran out of day");
|
215 |
"Imeis today's ticks have reached so far; catches up to due when the day clears");
|
| 161 |
gauge(registry, "imei_activation_captcha_shown", tags, captchaShown,
|
216 |
gauge(registry, "imei_activation_captcha_shown", tags, captchaShown,
|
| 162 |
"Captchas that rendered; collapses when the far end stops serving the widget");
|
217 |
"Captchas that rendered; collapses when the far end stops serving the widget");
|
| 163 |
gauge(registry, "imei_activation_captcha_solved", tags, captchaSolved,
|
218 |
gauge(registry, "imei_activation_captcha_solved", tags, captchaSolved,
|
| 164 |
"Captchas broken; divide by captcha_shown for the solver's accuracy");
|
219 |
"Captchas broken; divide by captcha_shown for the solver's accuracy");
|
| 165 |
gauge(registry, "imei_activation_answered", tags, answered,
|
220 |
gauge(registry, "imei_activation_answered", tags, answered,
|