Skip to content

Commit e86b877

Browse files
author
Lukáš Ondráček
committed
daemon/defer: use async-signal-safe formatting on SIGALRM
1 parent d5c8c33 commit e86b877

File tree

3 files changed

+169
-14
lines changed

3 files changed

+169
-14
lines changed

‎daemon/defer.c

+164-11
Original file line numberDiff line numberDiff line change
@@ -58,8 +58,158 @@ V6_CONF = {1, V6_PREFIXES_CNT, V6_PREFIXES, V6_RATE_MULT, V6_SUBPRIO};
5858
// payload is counted either as part of session wire buffer (for stream) or as part of iter ctx (for datagrams)
5959

6060

61+
/// Async-signal-safe snprintf-like formatting function, it supports:
62+
/// * %s takes (char *);
63+
/// * %u takes unsigned, %NUMu allowed for padding with spaces or zeroes;
64+
/// * %x takes unsigned, %NUMx allowed;
65+
/// * %f takes double, behaves like %.3f;
66+
/// * %r takes (struct sockaddr *).
67+
int sigsafe_format(char *str, size_t size, const char *fmt, ...) {
68+
char *strp = str; // ptr just after last written char
69+
char *stre = str + size; // ptr just after str buffer
70+
const char digits[] ="0123456789abcdef";
71+
va_list ap;
72+
va_start(ap, fmt); // NOLINT, should be safe in GCC
73+
while (*fmt && (stre-strp > 1)) {
74+
const char *append_str = NULL;
75+
int append_len = -1;
76+
bool mod_zero = false;
77+
int mod_int = 0;
78+
int base = 10;
79+
char tmpstr[50];
80+
81+
if (*fmt != '%') {
82+
char *perc = strchr(fmt, '%');
83+
append_str = fmt;
84+
append_len = perc ? perc - fmt : strlen(fmt);
85+
fmt += append_len;
86+
} else while(fmt++, !append_str) {
87+
switch(*fmt) {
88+
case '%': // %%
89+
append_str = "%";
90+
break;
91+
case 's': // just %s
92+
append_str = va_arg(ap, char *); // NOLINT, should be safe in GCC
93+
break;
94+
case 'x': // %x, %#x, %0#x
95+
base = 16; // passthrough
96+
case 'u': { // %u, %#u, %0#u
97+
unsigned num = va_arg(ap, unsigned); // NOLINT, should be safe in GCC
98+
char *sp = tmpstr + sizeof(tmpstr);
99+
*--sp = '\0';
100+
while ((num > 0) || !*sp) {
101+
*--sp = digits[num % base];
102+
num /= base;
103+
mod_int--;
104+
}
105+
while (mod_int-- > 0) {
106+
*--sp = mod_zero ? '0' : ' ';
107+
}
108+
append_str = sp;
109+
} break;
110+
case 'f': { // just %f, behaves like %.3f
111+
double valf = va_arg(ap, double); // NOLINT, should be safe in GCC
112+
const char *sign = "";
113+
if (valf < 0) { sign = "-"; valf *= -1; }
114+
uint64_t vali = valf * 1000 + 0.5; // NOLINT(bugprone-incorrect-roundings), just minor imprecisions
115+
// larger numbers, NaNs, ... are not handled
116+
strp += sigsafe_format(strp, stre-strp, "%s%u.%03u", sign, (unsigned)(vali / 1000), (unsigned)(vali % 1000));
117+
append_str = "";
118+
} break;
119+
case 'r': { // just %r, takes (struct sockaddr *)
120+
struct sockaddr *addr = va_arg(ap, void *); // NOLINT, should be safe in GCC
121+
if (!addr) {
122+
append_str = "(null)";
123+
break;
124+
}
125+
switch (addr->sa_family) {
126+
case AF_UNIX:
127+
append_str = ((struct sockaddr_un *)addr)->sun_path;
128+
break;
129+
case AF_INET: {
130+
struct sockaddr_in *addr4 = (struct sockaddr_in *)addr;
131+
uint8_t *ipv4 = (uint8_t *)&(addr4->sin_addr);
132+
strp += sigsafe_format(strp, stre-strp, "%u.%u.%u.%u#%u", ipv4[0], ipv4[1], ipv4[2], ipv4[3], addr4->sin_port);
133+
append_str = "";
134+
} break;
135+
case AF_INET6: {
136+
struct sockaddr_in6 *addr6 = (struct sockaddr_in6 *)addr;
137+
uint8_t *ipv6 = (uint8_t *)&(addr6->sin6_addr);
138+
int mzb = -2, mze = 0; // maximal zero-filled gap begin (incl.) and end (excl.)
139+
{ // find longest gap
140+
int zb = 0, ze = 0;
141+
for (size_t i = 0; i < 16; i += 2) {
142+
if (!ipv6[i] && !ipv6[i+1]) {
143+
if (i == ze) {
144+
ze += 2;
145+
} else {
146+
if (ze - zb > mze - mzb) {
147+
mzb = zb; mze = ze;
148+
}
149+
zb = i; ze = i + 2;
150+
}
151+
}
152+
}
153+
if (ze - zb > mze - mzb) {
154+
mzb = zb; mze = ze;
155+
}
156+
}
157+
for (int i = -!mzb; i < 15; i++) {
158+
if (i == mzb) i = mze - 1; // after ':' (possibly for i=-1), skip sth. and continue with ':' (possibly for i=15)
159+
if (i%2) {
160+
if (strp < stre) *strp++ = ':';
161+
} else {
162+
strp += sigsafe_format(strp, stre-strp, "%x", (ipv6[i] << 8) | ipv6[i+1]);
163+
}
164+
}
165+
strp += sigsafe_format(strp, stre-strp, "#%u", addr6->sin6_port);
166+
append_str = "";
167+
} break;
168+
case AF_UNSPEC:
169+
append_str = "(unspec)";
170+
break;
171+
default:
172+
append_str = "(unknown)";
173+
break;
174+
}
175+
} break;
176+
default:
177+
if (('0' <= *fmt) && (*fmt <= '9')) {
178+
if ((mod_int == 0) && (*fmt == '0')) {
179+
mod_zero = true;
180+
} else {
181+
mod_int = mod_int * 10 + *fmt - '0';
182+
}
183+
} else {
184+
append_str = "[ERR]";
185+
}
186+
break;
187+
}
188+
}
189+
190+
// append to str (without \0)
191+
append_len = MIN(append_len >= 0 ? append_len : strlen(append_str), stre-strp-1);
192+
memcpy(strp, append_str, append_len);
193+
strp += append_len;
194+
}
195+
*strp = '\0';
196+
va_end(ap); // NOLINT, should be safe in GCC
197+
return strp-str;
198+
}
199+
61200
#define VERBOSE_LOG(...) kr_log_debug(DEFER, " | " __VA_ARGS__)
62201

202+
// Uses NON-STANDARD format string, see sigsafe_format above.
203+
#define SIGSAFE_LOG(max_size, ...) { \
204+
char msg[max_size]; \
205+
int len = sigsafe_format(msg, sizeof(msg), "[defer ] "__VA_ARGS__); \
206+
write(kr_log_target == LOG_TARGET_STDOUT ? 1 : 2, msg, len); \
207+
}
208+
#define SIGSAFE_VERBOSE_LOG(max_size, ...) { \
209+
if (kr_log_is_debug(DEFER, NULL)) /* NOLINT */\
210+
{ SIGSAFE_LOG(max_size, " | " __VA_ARGS__)}}
211+
212+
63213
struct defer {
64214
size_t capacity;
65215
kru_price_t max_decay;
@@ -247,7 +397,8 @@ static inline int kru_charge_classify(const struct kru_conf *kru_conf, uint8_t *
247397
uint16_t *out_load, uint8_t *out_prefix)
248398
{
249399
uint16_t loads[kru_conf->prefixes_cnt];
250-
KRU.load_multi_prefix((struct kru *)defer->kru, kr_now(),
400+
const uint64_t now = kr_now(); // NOLINT, async-signal-safe, uv_now only reads uint64_t
401+
KRU.load_multi_prefix((struct kru *)defer->kru, now,
251402
kru_conf->namespace, key, kru_conf->prefixes, prices, kru_conf->prefixes_cnt, loads);
252403

253404
int priority = 0;
@@ -301,8 +452,9 @@ void defer_charge(uint64_t nsec, union kr_sockaddr *addr, bool stream)
301452
uint8_t prefix;
302453
kru_charge_classify(kru_conf, key, prices, &load, &prefix);
303454

304-
VERBOSE_LOG(" %s ADD %4.3f ms * %.2f -> load: %d on /%d\n",
305-
kr_straddr(&addr->ip), nsec / 1000000.0, pf16 / (float)(1<<16), load, prefix);
455+
SIGSAFE_VERBOSE_LOG(KR_STRADDR_MAXLEN + 100,
456+
" %r ADD %f ms * %f -> load: %u on /%u\n",
457+
&addr->ip, nsec / 1000000.0, pf16 / (float)(1<<16), load, prefix);
306458
}
307459

308460
/// Determine priority of the request in [0, QUEUES_CNT - 1];
@@ -651,21 +803,22 @@ static void defer_alarm(int signum)
651803
uint64_t elapsed = 0;
652804
if (defer_sample_state.is_accounting) {
653805
elapsed = defer_get_stamp() - defer_sample_state.stamp;
654-
VERBOSE_LOG("SIGALRM %s, host %s used %.3f s of cpu time on ongoing operation\n",
806+
SIGSAFE_VERBOSE_LOG(KR_STRADDR_MAXLEN + 100,
807+
"SIGALRM %s, host %r used %f s of cpu time on ongoing operation.\n",
655808
signum ? "received" : "initialized",
656-
kr_straddr(&defer_sample_state.addr.ip), elapsed / 1000000000.0); // XXX
809+
&defer_sample_state.addr.ip, elapsed / 1000000000.0);
657810
} else {
658-
VERBOSE_LOG("SIGALRM %s, no measuring in progress\n",
811+
SIGSAFE_VERBOSE_LOG(KR_STRADDR_MAXLEN + 100,
812+
"SIGALRM %s, no measuring in progress.\n",
659813
signum ? "received" : "initialized");
660814
}
661815
int64_t rest_to_timeout_ms = defer->hard_timeout - elapsed / 1000000; // ms - ns
816+
662817
if (rest_to_timeout_ms <= 0) {
663-
uv_update_time(uv_default_loop()); // TODO more conceptual solution?
664818
defer_charge(elapsed, &defer_sample_state.addr, defer_sample_state.stream);
665-
kr_log_crit(DEFER, "Host %s used %0.3f s of cpu time continuously, interrupting cresd.\n",
666-
kr_straddr(&defer_sample_state.addr.ip), elapsed / 1000000000.0);
667-
classify(&defer_sample_state.addr, defer_sample_state.stream); // XXX
668-
__sync_synchronize();
819+
SIGSAFE_LOG(KR_STRADDR_MAXLEN + 100,
820+
"Host %r used %f s of cpu time continuously, interrupting kresd.\n",
821+
&defer_sample_state.addr.ip, elapsed / 1000000000.0);
669822
abort();
670823
}
671824
alarm((rest_to_timeout_ms + 999) / 1000);

‎daemon/defer.h

+3-1
Original file line numberDiff line numberDiff line change
@@ -48,7 +48,9 @@ static inline uint64_t defer_get_stamp(void)
4848
uint64_t stamp = now_ts.tv_nsec + 1000*1000*1000 * (uint64_t)now_ts.tv_sec;
4949
if (defer_uvtime_stamp + 1000*1000 < stamp) {
5050
defer_uvtime_stamp = stamp;
51-
uv_update_time(uv_default_loop());
51+
uv_update_time(uv_default_loop()); // NOLINT, async-signal-safe
52+
// on Linux, it just calls clock_gettime(CLOCK_MONOTONIC[_COARSE], ...) and sets value for uv_now (kr_now);
53+
// libuv probably updates time just once per loop by itself
5254
}
5355
return stamp;
5456
}

‎doc/_static/config.schema.json

+2-2
Original file line numberDiff line numberDiff line change
@@ -374,7 +374,7 @@
374374
}
375375
},
376376
"default": {
377-
"files_watchdog": false,
377+
"files_watchdog": true,
378378
"cert_file": null,
379379
"key_file": null,
380380
"sticket_secret": null,
@@ -533,7 +533,7 @@
533533
},
534534
"address_renumbering": null,
535535
"tls": {
536-
"files_watchdog": false,
536+
"files_watchdog": true,
537537
"cert_file": null,
538538
"key_file": null,
539539
"sticket_secret": null,

0 commit comments

Comments
 (0)