optimization for a large alarm log; switched many messages from INFO to DEBUG
Costa Tsaousis (ktsaou) committed
Oct 18, 2016 at 02:17 UTC
7ab3b2f74d3b82c84a11daa1751e5d9e9ddf0af7
1 file changed
+60
-56
src/health.c
+60
-56
@@ -175,7 +175,7 @@ static inline ssize_t health_alarm_log_read(RRDHOST *host, FILE *fp, const char
175
ALARM_ENTRY *ae = NULL;
176
177
if(entries < 26) {
178
- error("Health: line %zu of file '%s' should have at least 26 entries, but it has %d. Ignoring line.", line, filename, entries);
178
+ error("Health: line %zu of file '%s' should have at least 26 entries, but it has %d. Ignoring it.", line, filename, entries);
179
errored++;
180
continue;
181
}
@@ -183,51 +183,58 @@ static inline ssize_t health_alarm_log_read(RRDHOST *host, FILE *fp, const char
183
// check that we have valid ids
184
uint32_t unique_id = (uint32_t)strtoul(pointers[2], NULL, 16);
185
if(!unique_id) {
186
- error("Health: line %zu of file '%s' states alarm entry with unique id %u (%s). Ignoring line.", line, filename, unique_id, pointers[2]);
186
+ error("Health: line %zu of file '%s' states alarm entry with invalid unique id %u (%s). Ignoring it.", line, filename, unique_id, pointers[2]);
187
errored++;
188
continue;
189
}
190
191
uint32_t alarm_id = (uint32_t)strtoul(pointers[3], NULL, 16);
192
if(!alarm_id) {
193
- error("Health: line %zu of file '%s' states alarm entry for alarm id %u (%s). Ignoring line.", line, filename, alarm_id, pointers[3]);
193
+ error("Health: line %zu of file '%s' states alarm entry for invalid alarm id %u (%s). Ignoring it.", line, filename, alarm_id, pointers[3]);
194
errored++;
195
continue;
196
}
197
198
- // find a possible overwrite
199
- for(ae = host->health_log.alarms; ae; ae = ae->next) {
200
- if(unlikely(ae->unique_id == unique_id)) {
201
- if(unlikely(*pointers[0] == 'A')) {
202
- error("Health: line %zu of file '%s' adds duplicate alarm log entry with unique id %u."
203
- , line, filename, unique_id);
204
- *pointers[0] = 'U';
205
- duplicate++;
206
- }
207
- break;
198
+ if(unlikely(*pointers[0] == 'A')) {
199
+ // make sure it is properly numbered
200
+ if(unlikely(host->health_log.alarms && unique_id < host->health_log.alarms->unique_id)) {
201
+ error("Health: line %zu of file '%s' has alarm log entry with %u in wrong order. Ignoring it.", line, filename, unique_id);
202
+ errored++;
203
+ continue;
204
}
209
- }
210
-
211
- // if not found, create a new one
212
- if(likely(!ae)) {
205
214
- // if it is an update, but we haven't found it, make it an addition
215
- if(unlikely(*pointers[0] == 'U')) {
216
- *pointers[0] = 'A';
217
- error("Health: line %zu of file '%s' updates alarm log entry with unique id %u, but it is not found.", line, filename, unique_id);
206
+ ae = callocz(1, sizeof(ALARM_ENTRY));
207
+ }
208
+ else if(unlikely(*pointers[0] == 'U')) {
209
+ // find the original
210
+ for(ae = host->health_log.alarms; ae; ae = ae->next) {
211
+ if(unlikely(unique_id == ae->unique_id)) {
212
+ if(unlikely(*pointers[0] == 'A')) {
213
+ error("Health: line %zu of file '%s' adds duplicate alarm log entry with unique id %u. Using the later."
214
+ , line, filename, unique_id);
215
+ *pointers[0] = 'U';
216
+ duplicate++;
217
+ }
218
+ break;
219
+ }
220
+ else if(unlikely(unique_id > ae->unique_id)) {
221
+ // no need to continue
222
+ // the linked list is sorted
223
+ ae = NULL;
224
+ break;
225
+ }
226
}
227
220
- // alarms should be added in the right order
221
- if(unlikely(unique_id < max_unique_id)) {
222
- error("Health: line %zu of file '%s' has alarm log entry with %u in wrong order.", line, filename, unique_id);
228
+ // if not found, skip this line
229
+ if(!ae) {
230
+ // error("Health: line %zu of file '%s' updates alarm log entry with unique id %u, but it is not found.", line, filename, unique_id);
231
+ continue;
232
}
224
-
225
- ae = callocz(1, sizeof(ALARM_ENTRY));
233
}
234
235
// check for a possible host missmatch
229
- if(strcmp(pointers[1], host->hostname))
230
- error("Health: line %zu of file '%s' provides an alarm for host '%s' but this is named '%s'.", line, filename, pointers[1], host->hostname);
236
+ //if(strcmp(pointers[1], host->hostname))
237
+ // error("Health: line %zu of file '%s' provides an alarm for host '%s' but this is named '%s'.", line, filename, pointers[1], host->hostname);
238
239
ae->unique_id = unique_id;
240
ae->alarm_id = alarm_id;
@@ -314,20 +321,20 @@ static inline ssize_t health_alarm_log_read(RRDHOST *host, FILE *fp, const char
321
host->health_log.next_log_id = max_unique_id + 1;
322
host->health_log.next_alarm_id = max_alarm_id + 1;
323
317
- info("Health: loaded file '%s' with %zd new alarm entries, updated %zd alarms, errors %zd entries, duplicate %zd", filename, loaded, updated, errored, duplicate);
324
+ debug(D_HEALTH, "Health: loaded file '%s' with %zd new alarm entries, updated %zd alarms, errors %zd entries, duplicate %zd", filename, loaded, updated, errored, duplicate);
325
return loaded;
326
}
327
328
static inline void health_alarm_log_load(RRDHOST *host) {
329
health_alarm_log_close();
330
324
- char buffer[FILENAME_MAX + 1];
325
- snprintfz(buffer, FILENAME_MAX, "%s.old", health.log_filename);
326
- FILE *fp = fopen(buffer, "r");
331
+ char filename[FILENAME_MAX + 1];
332
+ snprintfz(filename, FILENAME_MAX, "%s.old", health.log_filename);
333
+ FILE *fp = fopen(filename, "r");
334
if(!fp)
328
- error("Health: cannot open health file: %s", health.log_filename);
335
+ error("Health: cannot open health file: %s", filename);
336
else {
330
- health_alarm_log_read(host, fp, health.log_filename);
337
+ health_alarm_log_read(host, fp, filename);
338
fclose(fp);
339
}
340
@@ -1668,10 +1675,8 @@ int health_readfile(const char *path, const char *filename) {
1675
while((s = fgets(&buffer[append], (int)(HEALTH_CONF_MAX_LINE - append), fp)) || append) {
1676
int stop_appending = !s;
1677
line++;
1671
- // info("Line %zu of file '%s/%s': '%s'", line, path, filename, s);
1678
s = trim(buffer);
1679
if(!s) continue;
1674
- // info("Trimmed line %zu of file '%s/%s': '%s'", line, path, filename, s);
1680
1681
append = strlen(s);
1682
if(!stop_appending && s[append - 1] == '\\') {
@@ -1708,7 +1713,6 @@ int health_readfile(const char *path, const char *filename) {
1713
continue;
1714
}
1715
1711
- // info("Health file '%s/%s', key '%s', value '%s'", path, filename, key, value);
1716
uint32_t hash = simple_uhash(key);
1717
1718
if(hash == hash_alarm && !strcasecmp(key, HEALTH_ALARM_KEY)) {
@@ -1760,7 +1764,7 @@ int health_readfile(const char *path, const char *filename) {
1764
if(hash == hash_on && !strcasecmp(key, HEALTH_ON_KEY)) {
1765
if(rc->chart) {
1766
if(strcmp(rc->chart, value))
1763
- info("Health configuration at line %zu of file '%s/%s' for alarm '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1767
+ error("Health configuration at line %zu of file '%s/%s' for alarm '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1768
line, path, filename, rc->name, key, rc->chart, value, value);
1769
1770
freez(rc->chart);
@@ -1775,14 +1779,14 @@ int health_readfile(const char *path, const char *filename) {
1779
}
1780
else if(hash == hash_every && !strcasecmp(key, HEALTH_EVERY_KEY)) {
1781
if(!health_parse_duration(value, &rc->update_every))
1778
- info("Health configuration at line %zu of file '%s/%s' for alarm '%s' at key '%s' cannot parse duration: '%s'.",
1782
+ error("Health configuration at line %zu of file '%s/%s' for alarm '%s' at key '%s' cannot parse duration: '%s'.",
1783
line, path, filename, rc->name, key, value);
1784
}
1785
else if(hash == hash_green && !strcasecmp(key, HEALTH_GREEN_KEY)) {
1786
char *e;
1787
rc->green = strtold(value, &e);
1788
if(e && *e) {
1785
- info("Health configuration at line %zu of file '%s/%s' for alarm '%s' at key '%s' leaves this string unmatched: '%s'.",
1789
+ error("Health configuration at line %zu of file '%s/%s' for alarm '%s' at key '%s' leaves this string unmatched: '%s'.",
1790
line, path, filename, rc->name, key, e);
1791
}
1792
}
@@ -1790,7 +1794,7 @@ int health_readfile(const char *path, const char *filename) {
1794
char *e;
1795
rc->red = strtold(value, &e);
1796
if(e && *e) {
1793
- info("Health configuration at line %zu of file '%s/%s' for alarm '%s' at key '%s' leaves this string unmatched: '%s'.",
1797
+ error("Health configuration at line %zu of file '%s/%s' for alarm '%s' at key '%s' leaves this string unmatched: '%s'.",
1798
line, path, filename, rc->name, key, e);
1799
}
1800
}
@@ -1824,7 +1828,7 @@ int health_readfile(const char *path, const char *filename) {
1828
else if(hash == hash_exec && !strcasecmp(key, HEALTH_EXEC_KEY)) {
1829
if(rc->exec) {
1830
if(strcmp(rc->exec, value))
1827
- info("Health configuration at line %zu of file '%s/%s' for alarm '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1831
+ error("Health configuration at line %zu of file '%s/%s' for alarm '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1832
line, path, filename, rc->name, key, rc->exec, value, value);
1833
1834
freez(rc->exec);
@@ -1834,7 +1838,7 @@ int health_readfile(const char *path, const char *filename) {
1838
else if(hash == hash_recipient && !strcasecmp(key, HEALTH_RECIPIENT_KEY)) {
1839
if(rc->recipient) {
1840
if(strcmp(rc->recipient, value))
1837
- info("Health configuration at line %zu of file '%s/%s' for alarm '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1841
+ error("Health configuration at line %zu of file '%s/%s' for alarm '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1842
line, path, filename, rc->name, key, rc->recipient, value, value);
1843
1844
freez(rc->recipient);
@@ -1844,7 +1848,7 @@ int health_readfile(const char *path, const char *filename) {
1848
else if(hash == hash_units && !strcasecmp(key, HEALTH_UNITS_KEY)) {
1849
if(rc->units) {
1850
if(strcmp(rc->units, value))
1847
- info("Health configuration at line %zu of file '%s/%s' for alarm '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1851
+ error("Health configuration at line %zu of file '%s/%s' for alarm '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1852
line, path, filename, rc->name, key, rc->units, value, value);
1853
1854
freez(rc->units);
@@ -1855,7 +1859,7 @@ int health_readfile(const char *path, const char *filename) {
1859
else if(hash == hash_info && !strcasecmp(key, HEALTH_INFO_KEY)) {
1860
if(rc->info) {
1861
if(strcmp(rc->info, value))
1858
- info("Health configuration at line %zu of file '%s/%s' for alarm '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1862
+ error("Health configuration at line %zu of file '%s/%s' for alarm '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1863
line, path, filename, rc->name, key, rc->info, value, value);
1864
1865
freez(rc->info);
@@ -1875,7 +1879,7 @@ int health_readfile(const char *path, const char *filename) {
1879
if(hash == hash_on && !strcasecmp(key, HEALTH_ON_KEY)) {
1880
if(rt->context) {
1881
if(strcmp(rt->context, value))
1878
- info("Health configuration at line %zu of file '%s/%s' for template '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1882
+ error("Health configuration at line %zu of file '%s/%s' for template '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1883
line, path, filename, rt->name, key, rt->context, value, value);
1884
1885
freez(rt->context);
@@ -1890,14 +1894,14 @@ int health_readfile(const char *path, const char *filename) {
1894
}
1895
else if(hash == hash_every && !strcasecmp(key, HEALTH_EVERY_KEY)) {
1896
if(!health_parse_duration(value, &rt->update_every))
1893
- info("Health configuration at line %zu of file '%s/%s' for template '%s' at key '%s' cannot parse duration: '%s'.",
1897
+ error("Health configuration at line %zu of file '%s/%s' for template '%s' at key '%s' cannot parse duration: '%s'.",
1898
line, path, filename, rt->name, key, value);
1899
}
1900
else if(hash == hash_green && !strcasecmp(key, HEALTH_GREEN_KEY)) {
1901
char *e;
1902
rt->green = strtold(value, &e);
1903
if(e && *e) {
1900
- info("Health configuration at line %zu of file '%s/%s' for template '%s' at key '%s' leaves this string unmatched: '%s'.",
1904
+ error("Health configuration at line %zu of file '%s/%s' for template '%s' at key '%s' leaves this string unmatched: '%s'.",
1905
line, path, filename, rt->name, key, e);
1906
}
1907
}
@@ -1905,7 +1909,7 @@ int health_readfile(const char *path, const char *filename) {
1909
char *e;
1910
rt->red = strtold(value, &e);
1911
if(e && *e) {
1908
- info("Health configuration at line %zu of file '%s/%s' for template '%s' at key '%s' leaves this string unmatched: '%s'.",
1912
+ error("Health configuration at line %zu of file '%s/%s' for template '%s' at key '%s' leaves this string unmatched: '%s'.",
1913
line, path, filename, rt->name, key, e);
1914
}
1915
}
@@ -1939,7 +1943,7 @@ int health_readfile(const char *path, const char *filename) {
1943
else if(hash == hash_exec && !strcasecmp(key, HEALTH_EXEC_KEY)) {
1944
if(rt->exec) {
1945
if(strcmp(rt->exec, value))
1942
- info("Health configuration at line %zu of file '%s/%s' for template '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1946
+ error("Health configuration at line %zu of file '%s/%s' for template '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1947
line, path, filename, rt->name, key, rt->exec, value, value);
1948
1949
freez(rt->exec);
@@ -1949,7 +1953,7 @@ int health_readfile(const char *path, const char *filename) {
1953
else if(hash == hash_recipient && !strcasecmp(key, HEALTH_RECIPIENT_KEY)) {
1954
if(rt->recipient) {
1955
if(strcmp(rt->recipient, value))
1952
- info("Health configuration at line %zu of file '%s/%s' for template '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1956
+ error("Health configuration at line %zu of file '%s/%s' for template '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1957
line, path, filename, rt->name, key, rt->recipient, value, value);
1958
1959
freez(rt->recipient);
@@ -1959,7 +1963,7 @@ int health_readfile(const char *path, const char *filename) {
1963
else if(hash == hash_units && !strcasecmp(key, HEALTH_UNITS_KEY)) {
1964
if(rt->units) {
1965
if(strcmp(rt->units, value))
1962
- info("Health configuration at line %zu of file '%s/%s' for template '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1966
+ error("Health configuration at line %zu of file '%s/%s' for template '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1967
line, path, filename, rt->name, key, rt->units, value, value);
1968
1969
freez(rt->units);
@@ -1970,7 +1974,7 @@ int health_readfile(const char *path, const char *filename) {
1974
else if(hash == hash_info && !strcasecmp(key, HEALTH_INFO_KEY)) {
1975
if(rt->info) {
1976
if(strcmp(rt->info, value))
1973
- info("Health configuration at line %zu of file '%s/%s' for template '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1977
+ error("Health configuration at line %zu of file '%s/%s' for template '%s' has key '%s' twice, once with value '%s' and later with value '%s'. Using ('%s').",
1978
line, path, filename, rt->name, key, rt->info, value, value);
1979
1980
freez(rt->info);
@@ -2412,7 +2416,7 @@ static inline void health_alarm_execute(RRDHOST *host, ALARM_ENTRY *ae) {
2416
// we have executed this alarm notification in the past
2417
if (t && t->new_status == ae->new_status) {
2418
// don't send the same notification again
2415
- info("Health not sending again notification for alarm '%s.%s' status %s", ae->chart, ae->name,
2419
+ debug(D_HEALTH, "Health not sending again notification for alarm '%s.%s' status %s", ae->chart, ae->name,
2420
rrdcalc_status2string(ae->new_status));
2421
goto done;
2422
}
@@ -2420,7 +2424,7 @@ static inline void health_alarm_execute(RRDHOST *host, ALARM_ENTRY *ae) {
2424
else {
2425
// we have not executed this alarm notification in the past
2426
if(unlikely(ae->old_status == RRDCALC_STATUS_UNINITIALIZED && ae->new_status == RRDCALC_STATUS_CLEAR)) {
2423
- info("Health not sending notification for first initialization of alarm '%s.%s' status %s", ae->chart, ae->name, rrdcalc_status2string(ae->new_status));
2427
+ debug(D_HEALTH, "Health not sending notification for first initialization of alarm '%s.%s' status %s", ae->chart, ae->name, rrdcalc_status2string(ae->new_status));
2428
goto done;
2429
}
2430
}
@@ -2480,7 +2484,7 @@ done:
2484
}
2485
2486
static inline void health_process_notifications(RRDHOST *host, ALARM_ENTRY *ae) {
2483
- info("Health alarm '%s.%s' = %0.2Lf - changed status from %s to %s",
2487
+ debug(D_HEALTH, "Health alarm '%s.%s' = %0.2Lf - changed status from %s to %s",
2488
ae->chart?ae->chart:"NOCHART", ae->name,
2489
ae->new_value,
2490
rrdcalc_status2string(ae->old_status),