Fix MRG Metric refcount issue (#17239)
* add more detailed logging about metrics refcount issues * metric release by acquiring it for deletion
Costa Tsaousis committed
Mar 24, 2024 at 19:01 UTC
e81b427e0de10258fb70d4390cca66aea5eb81b8
4 files changed
+181
-119
src/database/engine/metric.c
+156
-119
@@ -17,8 +17,6 @@ struct metric {
17
uint32_t latest_update_every_s; // the latest data collection frequency
18
pid_t writer;
19
uint8_t partition;
20
-
21
- SPINLOCK refcount_spinlock;
20
REFCOUNT refcount;
21
22
// THIS IS allocated with malloc()
@@ -133,91 +131,174 @@ static inline time_t mrg_metric_get_first_time_s_smart(MRG *mrg __maybe_unused,
131
return first_time_s;
132
}
133
136
-static inline REFCOUNT metric_acquire(MRG *mrg __maybe_unused, METRIC *metric) {
137
- spinlock_lock(&metric->refcount_spinlock);
134
+static void metric_log(MRG *mrg __maybe_unused, METRIC *metric, const char *msg) {
135
+ struct rrdengine_instance *ctx = (struct rrdengine_instance *)metric->section;
136
+
137
+ char uuid[UUID_STR_LEN];
138
+ uuid_unparse_lower(metric->uuid, uuid);
139
+ nd_log(NDLS_DAEMON, NDLP_ERR,
140
+ "METRIC: %s on %s at tier %d, refcount %d, partition %u, "
141
+ "retention [%ld - %ld (hot), %ld (clean)], update every %"PRIu32", "
142
+ "writer pid %d "
143
+ "--- PLEASE OPEN A GITHUB ISSUE TO REPORT THIS LOG LINE TO NETDATA --- ",
144
+ msg,
145
+ uuid,
146
+ ctx->config.tier,
147
+ metric->refcount,
148
+ metric->partition,
149
+ metric->first_time_s,
150
+ metric->latest_time_s_hot,
151
+ metric->latest_time_s_clean,
152
+ metric->latest_update_every_s,
153
+ (int)metric->writer
154
+ );
155
+}
156
+
157
+static inline bool acquired_metric_has_retention(MRG *mrg, METRIC *metric) {
158
+ time_t first, last;
159
+ mrg_metric_get_retention(mrg, metric, &first, &last, NULL);
160
+ return (!first || !last || first > last);
161
+}
162
+
163
+static inline void acquired_for_deletion_metric_delete(MRG *mrg, METRIC *metric) {
164
+ size_t partition = metric->partition;
165
139
- if (metric->refcount >= 0)
140
- metric->refcount += 1;
141
- else
142
- fatal("METRIC: refcount is %d (negative) during acquire", metric->refcount);
166
+ size_t mem_before_judyl, mem_after_judyl;
167
+
168
+ mrg_index_write_lock(mrg, partition);
169
+
170
+ Pvoid_t *sections_judy_pptr = JudyHSGet(mrg->index[partition].uuid_judy, &metric->uuid, sizeof(uuid_t));
171
+ if(unlikely(!sections_judy_pptr || !*sections_judy_pptr)) {
172
+ MRG_STATS_DELETE_MISS(mrg, partition);
173
+ mrg_index_write_unlock(mrg, partition);
174
+ return;
175
+ }
176
+
177
+ mem_before_judyl = JudyLMemUsed(*sections_judy_pptr);
178
+ int rc = JudyLDel(sections_judy_pptr, metric->section, PJE0);
179
+ mem_after_judyl = JudyLMemUsed(*sections_judy_pptr);
180
+ mrg_stats_size_judyl_change(mrg, mem_before_judyl, mem_after_judyl, partition);
181
+
182
+ if(unlikely(!rc)) {
183
+ MRG_STATS_DELETE_MISS(mrg, partition);
184
+ mrg_index_write_unlock(mrg, partition);
185
+ return;
186
+ }
187
+
188
+ if(!*sections_judy_pptr) {
189
+ rc = JudyHSDel(&mrg->index[partition].uuid_judy, &metric->uuid, sizeof(uuid_t), PJE0);
190
+ if(unlikely(!rc))
191
+ fatal("DBENGINE METRIC: cannot delete UUID from JudyHS");
192
+ mrg_stats_size_judyhs_removed_uuid(mrg, partition);
193
+ }
194
+
195
+ MRG_STATS_DELETED_METRIC(mrg, partition);
196
+
197
+ mrg_index_write_unlock(mrg, partition);
198
+
199
+ aral_freez(mrg->index[partition].aral, metric);
200
+}
201
+
202
+static inline bool metric_acquire(MRG *mrg, METRIC *metric) {
203
+ REFCOUNT expected, desired;
204
+
205
+ expected = __atomic_load_n(&metric->refcount, __ATOMIC_RELAXED);
206
144
- REFCOUNT refcount = metric->refcount;
145
- spinlock_unlock(&metric->refcount_spinlock);
207
+ do {
208
+ if(unlikely(expected < 0))
209
+ return false;
210
+
211
+ desired = expected + 1;
212
+
213
+ } while(!__atomic_compare_exchange_n(&metric->refcount, &expected, desired, false, __ATOMIC_ACQUIRE, __ATOMIC_RELAXED));
214
215
size_t partition = metric->partition;
148
- if(refcount == 1)
216
+
217
+ if(desired == 1)
218
__atomic_add_fetch(&mrg->index[partition].stats.entries_referenced, 1, __ATOMIC_RELAXED);
219
220
__atomic_add_fetch(&mrg->index[partition].stats.current_references, 1, __ATOMIC_RELAXED);
221
153
- return refcount;
222
+ return true;
223
}
224
156
-static inline void metric_release(MRG *mrg __maybe_unused, METRIC *metric) {
157
- spinlock_lock(&metric->refcount_spinlock);
225
+static inline bool metric_release(MRG *mrg, METRIC *metric, bool delete_if_last_without_retention) {
226
+ size_t partition = metric->partition;
227
+ REFCOUNT expected, desired;
228
+
229
+ expected = __atomic_load_n(&metric->refcount, __ATOMIC_RELAXED);
230
159
- if (metric->refcount <= 0)
160
- fatal("METRIC: refcount is %d (zero or negative) during release", metric->refcount);
231
+ do {
232
+ if(expected <= 0) {
233
+ metric_log(mrg, metric, "refcount is zero or negative during release");
234
+ fatal("METRIC: refcount is %d (zero or negative) during release", expected);
235
+ }
236
162
- metric->refcount -= 1;
163
- REFCOUNT refcount = metric->refcount;
237
+ if(expected == 1 && delete_if_last_without_retention && !acquired_metric_has_retention(mrg, metric))
238
+ desired = REFCOUNT_DELETING;
239
+ else
240
+ desired = expected - 1;
241
165
- spinlock_unlock(&metric->refcount_spinlock);
242
+ } while(!__atomic_compare_exchange_n(&metric->refcount, &expected, desired, false, __ATOMIC_RELEASE, __ATOMIC_RELAXED));
243
167
- size_t partition = metric->partition;
168
- if(unlikely(!refcount))
244
+ if(desired == 0 || desired == REFCOUNT_DELETING) {
245
__atomic_sub_fetch(&mrg->index[partition].stats.entries_referenced, 1, __ATOMIC_RELAXED);
246
171
- __atomic_sub_fetch(&mrg->index[partition].stats.current_references, 1, __ATOMIC_RELAXED);
172
-}
247
+ if(desired == REFCOUNT_DELETING)
248
+ acquired_for_deletion_metric_delete(mrg, metric);
249
+ }
250
174
-static inline bool metric_release_and_can_be_deleted(MRG *mrg __maybe_unused, METRIC *metric) {
175
- metric_release(mrg, metric);
251
+ __atomic_sub_fetch(&mrg->index[partition].stats.current_references, 1, __ATOMIC_RELAXED);
252
177
- time_t first, last;
178
- mrg_metric_get_retention(mrg, metric, &first, &last, NULL);
179
- return (!first || !last || first > last);
253
+ return desired == REFCOUNT_DELETING;
254
}
255
256
static inline METRIC *metric_add_and_acquire(MRG *mrg, MRG_ENTRY *entry, bool *ret) {
257
size_t partition = uuid_partition(mrg, entry->uuid);
258
259
METRIC *allocation = aral_mallocz(mrg->index[partition].aral);
260
+ Pvoid_t *PValue;
261
187
- mrg_index_write_lock(mrg, partition);
262
+ while(1) {
263
+ mrg_index_write_lock(mrg, partition);
264
189
- size_t mem_before_judyl, mem_after_judyl;
265
+ size_t mem_before_judyl, mem_after_judyl;
266
191
- Pvoid_t *sections_judy_pptr = JudyHSIns(&mrg->index[partition].uuid_judy, entry->uuid, sizeof(uuid_t), PJE0);
192
- if(unlikely(!sections_judy_pptr || sections_judy_pptr == PJERR))
193
- fatal("DBENGINE METRIC: corrupted UUIDs JudyHS array");
267
+ Pvoid_t *sections_judy_pptr = JudyHSIns(&mrg->index[partition].uuid_judy, entry->uuid, sizeof(uuid_t), PJE0);
268
+ if (unlikely(!sections_judy_pptr || sections_judy_pptr == PJERR))
269
+ fatal("DBENGINE METRIC: corrupted UUIDs JudyHS array");
270
195
- if(unlikely(!*sections_judy_pptr))
196
- mrg_stats_size_judyhs_added_uuid(mrg, partition);
271
+ if (unlikely(!*sections_judy_pptr))
272
+ mrg_stats_size_judyhs_added_uuid(mrg, partition);
273
198
- mem_before_judyl = JudyLMemUsed(*sections_judy_pptr);
199
- Pvoid_t *PValue = JudyLIns(sections_judy_pptr, entry->section, PJE0);
200
- mem_after_judyl = JudyLMemUsed(*sections_judy_pptr);
201
- mrg_stats_size_judyl_change(mrg, mem_before_judyl, mem_after_judyl, partition);
274
+ mem_before_judyl = JudyLMemUsed(*sections_judy_pptr);
275
+ PValue = JudyLIns(sections_judy_pptr, entry->section, PJE0);
276
+ mem_after_judyl = JudyLMemUsed(*sections_judy_pptr);
277
+ mrg_stats_size_judyl_change(mrg, mem_before_judyl, mem_after_judyl, partition);
278
203
- if(unlikely(!PValue || PValue == PJERR))
204
- fatal("DBENGINE METRIC: corrupted section JudyL array");
279
+ if (unlikely(!PValue || PValue == PJERR))
280
+ fatal("DBENGINE METRIC: corrupted section JudyL array");
281
206
- if(unlikely(*PValue != NULL)) {
207
- METRIC *metric = *PValue;
282
+ if (unlikely(*PValue != NULL)) {
283
+ METRIC *metric = *PValue;
284
209
- metric_acquire(mrg, metric);
285
+ if(!metric_acquire(mrg, metric)) {
286
+ mrg_index_write_unlock(mrg, partition);
287
+ continue;
288
+ }
289
211
- MRG_STATS_DUPLICATE_ADD(mrg, partition);
290
+ MRG_STATS_DUPLICATE_ADD(mrg, partition);
291
+ mrg_index_write_unlock(mrg, partition);
292
213
- mrg_index_write_unlock(mrg, partition);
293
+ if (ret)
294
+ *ret = false;
295
215
- if(ret)
216
- *ret = false;
296
+ aral_freez(mrg->index[partition].aral, allocation);
297
218
- aral_freez(mrg->index[partition].aral, allocation);
298
+ return metric;
299
+ }
300
220
- return metric;
301
+ break;
302
}
303
304
METRIC *metric = allocation;
@@ -228,10 +309,8 @@ static inline METRIC *metric_add_and_acquire(MRG *mrg, MRG_ENTRY *entry, bool *r
309
metric->latest_time_s_hot = 0;
310
metric->latest_update_every_s = entry->latest_update_every_s;
311
metric->writer = 0;
231
- metric->refcount = 0;
312
+ metric->refcount = 1;
313
metric->partition = partition;
233
- spinlock_init(&metric->refcount_spinlock);
234
- metric_acquire(mrg, metric);
314
*PValue = metric;
315
316
MRG_STATS_ADDED_METRIC(mrg, partition);
@@ -247,77 +326,35 @@ static inline METRIC *metric_add_and_acquire(MRG *mrg, MRG_ENTRY *entry, bool *r
326
static inline METRIC *metric_get_and_acquire(MRG *mrg, uuid_t *uuid, Word_t section) {
327
size_t partition = uuid_partition(mrg, uuid);
328
250
- mrg_index_read_lock(mrg, partition);
329
+ while(1) {
330
+ mrg_index_read_lock(mrg, partition);
331
252
- Pvoid_t *sections_judy_pptr = JudyHSGet(mrg->index[partition].uuid_judy, uuid, sizeof(uuid_t));
253
- if(unlikely(!sections_judy_pptr)) {
254
- mrg_index_read_unlock(mrg, partition);
255
- MRG_STATS_SEARCH_MISS(mrg, partition);
256
- return NULL;
257
- }
258
-
259
- Pvoid_t *PValue = JudyLGet(*sections_judy_pptr, section, PJE0);
260
- if(unlikely(!PValue)) {
261
- mrg_index_read_unlock(mrg, partition);
262
- MRG_STATS_SEARCH_MISS(mrg, partition);
263
- return NULL;
264
- }
265
-
266
- METRIC *metric = *PValue;
267
-
268
- metric_acquire(mrg, metric);
269
-
270
- mrg_index_read_unlock(mrg, partition);
271
-
272
- MRG_STATS_SEARCH_HIT(mrg, partition);
273
- return metric;
274
-}
275
-
276
-static inline bool acquired_metric_del(MRG *mrg, METRIC *metric) {
277
- size_t partition = metric->partition;
278
-
279
- size_t mem_before_judyl, mem_after_judyl;
280
-
281
- mrg_index_write_lock(mrg, partition);
332
+ Pvoid_t *sections_judy_pptr = JudyHSGet(mrg->index[partition].uuid_judy, uuid, sizeof(uuid_t));
333
+ if (unlikely(!sections_judy_pptr)) {
334
+ mrg_index_read_unlock(mrg, partition);
335
+ MRG_STATS_SEARCH_MISS(mrg, partition);
336
+ return NULL;
337
+ }
338
283
- if(!metric_release_and_can_be_deleted(mrg, metric)) {
284
- mrg->index[partition].stats.delete_having_retention_or_referenced++;
285
- mrg_index_write_unlock(mrg, partition);
286
- return false;
287
- }
339
+ Pvoid_t *PValue = JudyLGet(*sections_judy_pptr, section, PJE0);
340
+ if (unlikely(!PValue)) {
341
+ mrg_index_read_unlock(mrg, partition);
342
+ MRG_STATS_SEARCH_MISS(mrg, partition);
343
+ return NULL;
344
+ }
345
289
- Pvoid_t *sections_judy_pptr = JudyHSGet(mrg->index[partition].uuid_judy, &metric->uuid, sizeof(uuid_t));
290
- if(unlikely(!sections_judy_pptr || !*sections_judy_pptr)) {
291
- MRG_STATS_DELETE_MISS(mrg, partition);
292
- mrg_index_write_unlock(mrg, partition);
293
- return false;
294
- }
346
+ METRIC *metric = *PValue;
347
296
- mem_before_judyl = JudyLMemUsed(*sections_judy_pptr);
297
- int rc = JudyLDel(sections_judy_pptr, metric->section, PJE0);
298
- mem_after_judyl = JudyLMemUsed(*sections_judy_pptr);
299
- mrg_stats_size_judyl_change(mrg, mem_before_judyl, mem_after_judyl, partition);
348
+ if(metric && !metric_acquire(mrg, metric))
349
+ metric = NULL;
350
301
- if(unlikely(!rc)) {
302
- MRG_STATS_DELETE_MISS(mrg, partition);
303
- mrg_index_write_unlock(mrg, partition);
304
- return false;
305
- }
351
+ mrg_index_read_unlock(mrg, partition);
352
307
- if(!*sections_judy_pptr) {
308
- rc = JudyHSDel(&mrg->index[partition].uuid_judy, &metric->uuid, sizeof(uuid_t), PJE0);
309
- if(unlikely(!rc))
310
- fatal("DBENGINE METRIC: cannot delete UUID from JudyHS");
311
- mrg_stats_size_judyhs_removed_uuid(mrg, partition);
353
+ if(metric) {
354
+ MRG_STATS_SEARCH_HIT(mrg, partition);
355
+ return metric;
356
+ }
357
}
313
-
314
- MRG_STATS_DELETED_METRIC(mrg, partition);
315
-
316
- mrg_index_write_unlock(mrg, partition);
317
-
318
- aral_freez(mrg->index[partition].aral, metric);
319
-
320
- return true;
358
}
359
360
// ----------------------------------------------------------------------------
@@ -372,7 +409,7 @@ inline METRIC *mrg_metric_get_and_acquire(MRG *mrg, uuid_t *uuid, Word_t section
409
}
410
411
inline bool mrg_metric_release_and_delete(MRG *mrg, METRIC *metric) {
375
- return acquired_metric_del(mrg, metric);
412
+ return metric_release(mrg, metric, true);
413
}
414
415
inline METRIC *mrg_metric_dup(MRG *mrg, METRIC *metric) {
@@ -381,7 +418,7 @@ inline METRIC *mrg_metric_dup(MRG *mrg, METRIC *metric) {
418
}
419
420
inline void mrg_metric_release(MRG *mrg, METRIC *metric) {
384
- metric_release(mrg, metric);
421
+ metric_release(mrg, metric, false);
422
}
423
424
inline Word_t mrg_metric_id(MRG *mrg __maybe_unused, METRIC *metric) {
src/database/rrddim.c
+11
@@ -167,10 +167,20 @@ static void rrddim_insert_callback(const DICTIONARY_ITEM *item __maybe_unused, v
167
}
168
169
bool rrddim_finalize_collection_and_check_retention(RRDDIM *rd) {
170
+ ND_LOG_STACK lgs[] = {
171
+ ND_LOG_FIELD_TXT(NDF_NIDL_NODE, rrdhost_hostname(rd->rrdset->rrdhost)),
172
+ ND_LOG_FIELD_TXT(NDF_NIDL_CONTEXT, rrdset_context(rd->rrdset)),
173
+ ND_LOG_FIELD_TXT(NDF_NIDL_INSTANCE, rrdset_name(rd->rrdset)),
174
+ ND_LOG_FIELD_TXT(NDF_NIDL_DIMENSION, rrddim_name(rd)),
175
+ ND_LOG_FIELD_END(),
176
+ };
177
+ ND_LOG_STACK_PUSH(lgs);
178
+
179
size_t tiers_available = 0, tiers_said_no_retention = 0;
180
181
for(size_t tier = 0; tier < storage_tiers ;tier++) {
182
spinlock_lock(&rd->tiers[tier].spinlock);
183
+
184
if(rd->tiers[tier].sch) {
185
tiers_available++;
186
@@ -179,6 +189,7 @@ bool rrddim_finalize_collection_and_check_retention(RRDDIM *rd) {
189
190
rd->tiers[tier].sch = NULL;
191
}
192
+
193
spinlock_unlock(&rd->tiers[tier].spinlock);
194
}
195
src/database/rrdhost.c
+6
@@ -1523,6 +1523,12 @@ void reload_host_labels(void) {
1523
}
1524
1525
void rrdhost_finalize_collection(RRDHOST *host) {
1526
+ ND_LOG_STACK lgs[] = {
1527
+ ND_LOG_FIELD_TXT(NDF_NIDL_NODE, rrdhost_hostname(host)),
1528
+ ND_LOG_FIELD_END(),
1529
+ };
1530
+ ND_LOG_STACK_PUSH(lgs);
1531
+
1532
nd_log(NDLS_DAEMON, NDLP_DEBUG,
1533
"RRD: 'host:%s' stopping data collection...",
1534
rrdhost_hostname(host));
src/database/rrdset.c
+8
@@ -296,6 +296,14 @@ static void rrdset_insert_callback(const DICTIONARY_ITEM *item __maybe_unused, v
296
}
297
298
void rrdset_finalize_collection(RRDSET *st, bool dimensions_too) {
299
+ ND_LOG_STACK lgs[] = {
300
+ ND_LOG_FIELD_TXT(NDF_NIDL_NODE, rrdhost_hostname(st->rrdhost)),
301
+ ND_LOG_FIELD_TXT(NDF_NIDL_CONTEXT, rrdset_context(st)),
302
+ ND_LOG_FIELD_TXT(NDF_NIDL_INSTANCE, rrdset_name(st)),
303
+ ND_LOG_FIELD_END(),
304
+ };
305
+ ND_LOG_STACK_PUSH(lgs);
306
+
307
RRDHOST *host = st->rrdhost;
308
309
rrdset_flag_set(st, RRDSET_FLAG_COLLECTION_FINISHED);