1 /* _XOPEN_SOURCE >= 500 for vsnprintf() */
2 #ifndef _XOPEN_SOURCE
3 #define _XOPEN_SOURCE 700
4 #endif
5
6 #include "first.h"
7
8 #include "log.h"
9
10 #include <sys/types.h>
11 #include "sys-time.h"
12 #include <errno.h>
13 #include <string.h>
14 #include <stdarg.h>
15 #include <stdio.h> /* vsnprintf() */
16 #include <stdlib.h> /* malloc() free() */
17 #include <unistd.h>
18
19 #ifdef HAVE_SYSLOG_H
20 # include <syslog.h>
21 #endif
22
23 #include "ck.h"
24 #include "fdlog.h"
25
26 static fdlog_st log_stderrh = { FDLOG_FD, STDERR_FILENO, { NULL, 0, 0 }, NULL };
27 static fdlog_st *log_errh = &log_stderrh;
28 static unix_time64_t tlast;
29 static uint32_t thp;
30 static uint32_t tlen;
31 static char tstr[24]; /* 20 "%F %T" incl '\0' +2 ": " */
32
33 /* log_con_jqueue instance here to be defined in shared object (see base.h) */
34 connection *log_con_jqueue;
35
36 unix_time64_t log_epoch_secs = 0;
37 unix_time64_t log_monotonic_secs = 0;
38
39 #if !defined(HAVE_CLOCK_GETTIME) || !HAS_TIME_BITS64
40
log_clock_gettime(const int clockid,unix_timespec64_t * const ts)41 int log_clock_gettime (const int clockid, unix_timespec64_t * const ts) {
42 #ifdef HAVE_CLOCK_GETTIME
43 #if HAS_TIME_BITS64
44 return clock_gettime(clockid, ts);
45 #else
46 struct timespec ts32;
47 int rc = clock_gettime(clockid, &ts32);
48 if (0 == rc) {
49 /*(treat negative 32-bit tv.tv_sec as unsigned)*/
50 ts->tv_sec = TIME64_CAST(ts32.tv_sec);
51 ts->tv_nsec = ts32.tv_nsec;
52 }
53 return rc;
54 #endif
55 #else
56 /* Mac OSX before 10.12 Sierra does not provide clock_gettime()
57 * e.g. defined(__APPLE__) && defined(__MACH__)
58 * && __ENVIRONMENT_MAC_OS_X_VERSION_MIN_REQUIRED__ < 101200 */
59 struct timeval tv;
60 gettimeofday(&tv, NULL);
61 UNUSED(clockid);
62 #if HAS_TIME_BITS64
63 ts->tv_sec = tv.tv_sec;
64 #else /*(treat negative 32-bit tv.tv_sec as unsigned)*/
65 ts->tv_sec = TIME64_CAST(tv.tv_sec);
66 #endif
67 ts->tv_nsec = tv.tv_usec * 1000;
68 return 0;
69 #endif
70 }
71
log_clock_gettime_realtime(unix_timespec64_t * ts)72 int log_clock_gettime_realtime (unix_timespec64_t *ts) {
73 #ifdef HAVE_CLOCK_GETTIME
74 return log_clock_gettime(CLOCK_REALTIME, ts);
75 #else
76 return log_clock_gettime(0, ts);
77 #endif
78 }
79
80 #endif /* !defined(HAVE_CLOCK_GETTIME) || !HAS_TIME_BITS64 */
81
82
83 /* retry write on EINTR or when not all data was written */
write_all(int fd,const void * const buf,size_t count)84 ssize_t write_all(int fd, const void * const buf, size_t count) {
85 ssize_t written = 0;
86 ssize_t wr;
87
88 do {
89 wr = write(fd, (const char *)buf + written, count);
90 } while (wr > 0 ? (written += wr, count -= wr) : wr < 0 && errno == EINTR);
91
92 if (__builtin_expect( (0 == count), 1))
93 return written;
94 else {
95 if (0 == wr) errno = EIO; /* really shouldn't happen... */
96 return -1; /* fail - repeating probably won't help */
97 }
98 }
99
100
101 static void
log_buffer_tstr(const unix_time64_t t)102 log_buffer_tstr (const unix_time64_t t)
103 {
104 /* cache the generated timestamp */
105 struct tm tm;
106 tlast = t;
107 tlen = (uint32_t) strftime(tstr, sizeof(tstr), "%F %T",
108 localtime64_r(&tlast, &tm));
109 }
110
111
__attribute_nonnull__()112 __attribute_nonnull__()
113 static void
114 log_buffer_timestamp (buffer * const restrict b)
115 {
116 if (thp) { /* high-precision timestamp */
117 unix_timespec64_t ts = { 0, 0 };
118 log_clock_gettime_realtime(&ts);
119 #if 0
120 buffer_append_int(b, TIME64_CAST(ts.tv_sec));
121 buffer_append_string_len(b, CONST_STR_LEN(".000000000: "));
122 #else /*(closer to syslog time format RFC 3339)*/
123 if (__builtin_expect( (tlast != ts.tv_sec), 0))
124 log_buffer_tstr(ts.tv_sec);
125 buffer_append_str2(b, tstr, tlen, CONST_STR_LEN(".000000000: "));
126 #endif
127 char n[LI_ITOSTRING_LENGTH];
128 const size_t nlen =
129 li_utostrn(n, sizeof(n), (unsigned long)ts.tv_nsec);
130 memcpy(b->ptr+buffer_clen(b)-nlen-2, n, nlen);
131 }
132 else {
133 if (__builtin_expect( (tlast != log_epoch_secs), 0)) {
134 log_buffer_tstr(log_epoch_secs);
135 tstr[ tlen] = ':';
136 tstr[++tlen] = ' ';
137 /*tstr[++tlen] = '\0';*//*(not necessary for our use)*/
138 ++tlen;
139 }
140 buffer_copy_string_len(b, tstr, tlen);
141 }
142 }
143
144
__attribute_nonnull__()145 __attribute_nonnull__()
146 static void
147 log_buffer_prefix (buffer * const restrict b,
148 const char * const restrict filename,
149 const unsigned int line)
150 {
151 char lstr[LI_ITOSTRING_LENGTH];
152 struct const_iovec iov[] = {
153 { CONST_STR_LEN("(") }
154 ,{ filename, strlen(filename) }
155 ,{ CONST_STR_LEN(".") }
156 ,{ lstr, li_itostrn(lstr, sizeof(lstr), line) }
157 ,{ CONST_STR_LEN(") ") }
158 };
159 buffer_append_iovec(b, iov, sizeof(iov)/sizeof(*iov));
160 }
161
162
163 static void
log_buffer_append_encoded(buffer * const b,const char * const s,const size_t n)164 log_buffer_append_encoded (buffer * const b,
165 const char * const s, const size_t n)
166 {
167 size_t i;
168 for (i = 0; i < n && ' ' <= s[i] && s[i] <= '~'; ++i) ;/*(ASCII isprint())*/
169 if (i == n)
170 buffer_append_string_len(b, s, n); /* common case; nothing to encode */
171 else
172 buffer_append_string_c_escaped(b, s, n);
173 }
174
175
176 __attribute_format__((__printf__, 2, 0))
__attribute_nonnull__()177 __attribute_nonnull__()
178 static void
179 log_buffer_vsprintf (buffer * const restrict b,
180 const char * const restrict fmt, va_list ap)
181 {
182 /* NOTE: log_buffer_prefix() ensures 0 != b->used */
183 /*assert(0 != b->used);*//*(only because code calcs below assume this)*/
184 /*assert(0 != b->size);*//*(b has non-size after log_buffer_prefix())*/
185 size_t blen = buffer_clen(b);
186 size_t bsp = buffer_string_space(b)+1;
187 char *s = b->ptr + blen;
188 unsigned int n;
189
190 va_list aptry;
191 va_copy(aptry, ap);
192 n = (unsigned int)vsnprintf(s, bsp, fmt, aptry);
193 va_end(aptry);
194
195 if ((int)n <= 0)
196 return;
197 if (n < bsp)
198 buffer_truncate(b, blen+n); /*buffer_commit(b, n);*/
199 else {
200 s = buffer_extend(b, n);
201 vsnprintf(s, n+1, fmt, ap);
202 }
203
204 unsigned int i;
205 for (i = 0; i < n && ' ' <= s[i] && s[i] <= '~'; ++i) ;/*(ASCII isprint())*/
206 if (i == n) return; /* common case; nothing to encode */
207
208 /* need to encode log line
209 * copy original line fragment, append encoded line to buffer, free copy */
210 n -= i;
211 char * const src = (char *)ck_malloc(n);
212 memcpy(src, s+i, n); /*(note: not '\0'-terminated)*/
213 buffer_truncate(b, blen+i);
214 buffer_append_string_c_escaped(b, src, n);
215 free(src);
216 }
217
218
__attribute_nonnull__()219 __attribute_nonnull__()
220 static buffer *
221 log_buffer_prepare (const log_error_st * const errh,
222 const char * const restrict filename,
223 const unsigned int line)
224 {
225 buffer * const restrict b = &log_errh->b; /*(use shared temp buffer)*/
226 buffer_clear(b);
227 if (errh->mode != FDLOG_SYSLOG) { /*(syslog() generates its own timestamp)*/
228 if (-1 == errh->fd) return NULL;
229 log_buffer_timestamp(b);
230 }
231 log_buffer_prefix(b, filename, line);
232 return b;
233 }
234
235
__attribute_nonnull__()236 __attribute_nonnull__()
237 static void
238 log_error_write (const log_error_st * const errh, buffer * const restrict b)
239 {
240 if (errh->mode != FDLOG_SYSLOG) { /* FDLOG_FD FDLOG_FILE FDLOG_PIPE */
241 buffer_append_char(b, '\n');
242 write_all(errh->fd, BUF_PTR_LEN(b));
243 }
244 else {
245 syslog(LOG_ERR, "%s", b->ptr);
246 }
247 }
248
249
250 __attribute_noinline__
251 static void
log_error_append_strerror(buffer * const b,const int errnum)252 log_error_append_strerror (buffer * const b, const int errnum)
253 {
254 char buf[1024];
255 errno_t rc = ck_strerror_s(buf, sizeof(buf), errnum);
256 if (0 == rc || rc == ERANGE)
257 buffer_append_str2(b, CONST_STR_LEN(": "), buf, strlen(buf));
258 }
259
260
261 __attribute_format__((__printf__, 4, 0))
262 static void
log_error_va_list_impl(const log_error_st * errh,const char * const restrict filename,const unsigned int line,const char * const restrict fmt,va_list ap,const int perr)263 log_error_va_list_impl (const log_error_st *errh,
264 const char * const restrict filename,
265 const unsigned int line,
266 const char * const restrict fmt, va_list ap,
267 const int perr)
268 {
269 const int errnum = errno;
270
271 if (NULL == errh) errh = log_errh;
272 buffer * const restrict b = log_buffer_prepare(errh, filename, line);
273 if (NULL == b) return; /*(errno not modified if errh->fd == -1)*/
274
275 log_buffer_vsprintf(b, fmt, ap);
276 if (perr)
277 log_error_append_strerror(b, errnum);
278
279 log_error_write(errh, b);
280
281 buffer_clear(b);
282 errno = errnum;
283 }
284
285
286 void
log_error(log_error_st * const errh,const char * const filename,const unsigned int line,const char * fmt,...)287 log_error(log_error_st * const errh,
288 const char * const filename, const unsigned int line,
289 const char *fmt, ...)
290 {
291 va_list ap;
292 va_start(ap, fmt);
293 log_error_va_list_impl(errh, filename, line, fmt, ap, 0);
294 va_end(ap);
295 }
296
297
298 void
log_perror(log_error_st * const errh,const char * const filename,const unsigned int line,const char * const fmt,...)299 log_perror (log_error_st * const errh,
300 const char * const filename, const unsigned int line,
301 const char * const fmt, ...)
302 {
303 va_list ap;
304 va_start(ap, fmt);
305 log_error_va_list_impl(errh, filename, line, fmt, ap, 1);
306 va_end(ap);
307 }
308
309
310 void
log_error_multiline(log_error_st * errh,const char * const restrict filename,const unsigned int line,const char * const restrict multiline,const size_t len,const char * const restrict fmt,...)311 log_error_multiline (log_error_st *errh,
312 const char * const restrict filename,
313 const unsigned int line,
314 const char * const restrict multiline,
315 const size_t len,
316 const char * const restrict fmt, ...)
317 {
318 if (0 == len) return;
319
320 const int errnum = errno;
321
322 if (NULL == errh) errh = log_errh;
323 buffer * const restrict b = log_buffer_prepare(errh, filename, line);
324 if (NULL == b) return; /*(errno not modified if errh->fd == -1)*/
325
326 va_list ap;
327 va_start(ap, fmt);
328 log_buffer_vsprintf(b, fmt, ap);
329 va_end(ap);
330
331 const uint32_t prefix_len = buffer_clen(b);
332 const char * const end = multiline + len;
333 for (const char *pos = multiline; pos < end; ++pos) {
334 const char * const current_line = pos;
335 pos = strchr(pos, '\n');
336 if (!pos)
337 pos = end;
338 size_t n = (size_t)(pos - current_line);
339 if (n && current_line[n-1] == '\r') --n; /*(skip "\r\n")*/
340 buffer_truncate(b, prefix_len);
341 log_buffer_append_encoded(b, current_line, n);
342 log_error_write(errh, b);
343 }
344
345 buffer_clear(b);
346 errno = errnum;
347 }
348
349
350 log_error_st *
log_set_global_errh(log_error_st * const errh,const int ts_high_precision)351 log_set_global_errh (log_error_st * const errh, const int ts_high_precision)
352 {
353 /* reset tlast
354 * -1 for cached timestamp to not match log_epoch_secs
355 * (e.g. if realtime clock init at 0)
356 */
357 tlast = -1;
358 thp = ts_high_precision;
359
360 buffer_free_ptr(&log_stderrh.b);
361 return (log_errh = errh ? errh : &log_stderrh);
362 }
363