kore

An easy to use, scalable and secure web application framework for writing web APIs in C.
Commits | Files | Refs | README | LICENSE | git clone https://git.kore.io/kore.git

accesslog.c (7814B)



      1 /*
      2  * Copyright (c) 2013-2022 Joris Vink <joris@coders.se>
      3  *
      4  * Permission to use, copy, modify, and distribute this software for any
      5  * purpose with or without fee is hereby granted, provided that the above
      6  * copyright notice and this permission notice appear in all copies.
      7  *
      8  * THE SOFTWARE IS PROVIDED "AS IS" AND THE AUTHOR DISCLAIMS ALL WARRANTIES
      9  * WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF
     10  * MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR
     11  * ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES
     12  * WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN
     13  * ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF
     14  * OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
     15  */
     16 
     17 #include <sys/types.h>
     18 #include <sys/socket.h>
     19 
     20 #include <time.h>
     21 #include <inttypes.h>
     22 #include <signal.h>
     23 
     24 #include "kore.h"
     25 #include "http.h"
     26 
     27 /*
     28  * The worker will write accesslogs to its worker data structure which is
     29  * held in shared memory.
     30  *
     31  * Each accesslog is prefixed with the internal domain ID (2 bytes) and
     32  * the length of the log entry (2 bytes) (packed in kore_alog_header).
     33  *
     34  * The parent will every 10ms fetch the produced accesslogs from the workers
     35  * and copy them to its own log buffer. Once this log buffer becomes full
     36  * or 1 second has passed the parent will parse the logs and append them
     37  * to the correct domain logbuffer which is eventually flushed to disk.
     38  */
     39 
     40 #define LOGBUF_SIZE			(KORE_ACCESSLOG_BUFLEN * worker_count)
     41 #define DOMAIN_LOGBUF_LEN		(1024 * 1024)
     42 #define LOG_ENTRY_MINSIZE_GUESS		90
     43 
     44 static void	accesslog_lock(struct kore_worker *);
     45 static void	accesslog_unlock(struct kore_worker *);
     46 static void	accesslog_flush_cb(struct kore_domain *);
     47 static void	accesslog_flush(struct kore_domain *, u_int64_t, int);
     48 
     49 static u_int64_t	time_cache = 0;
     50 static char		tbuf[128] = { '\0' };
     51 
     52 static struct kore_buf	*logbuf = NULL;
     53 
     54 void
     55 kore_accesslog_worker_init(void)
     56 {
     57 	kore_domain_closelogs();
     58 }
     59 
     60 void
     61 kore_accesslog(struct http_request *req)
     62 {
     63 	struct timespec		ts;
     64 	struct tm		*tm;
     65 	u_int64_t		now;
     66 	struct kore_alog_header	*hdr;
     67 	size_t			avail;
     68 	time_t			curtime;
     69 	int			len, attempts;
     70 	char			addr[INET6_ADDRSTRLEN], *cn_value;
     71 	const char		*ptr, *method, *http_version, *cn, *referer;
     72 
     73 	switch (req->method) {
     74 	case HTTP_METHOD_GET:
     75 		method = "GET";
     76 		break;
     77 	case HTTP_METHOD_POST:
     78 		method = "POST";
     79 		break;
     80 	case HTTP_METHOD_PUT:
     81 		method = "PUT";
     82 		break;
     83 	case HTTP_METHOD_DELETE:
     84 		method = "DELETE";
     85 		break;
     86 	case HTTP_METHOD_HEAD:
     87 		method = "HEAD";
     88 		break;
     89 	case HTTP_METHOD_PATCH:
     90 		method = "PATCH";
     91 		break;
     92 	default:
     93 		method = "UNKNOWN";
     94 		break;
     95 	}
     96 
     97 	if (req->flags & HTTP_VERSION_1_0)
     98 		http_version = "HTTP/1.0";
     99 	else
    100 		http_version = "HTTP/1.1";
    101 
    102 	if (req->referer != NULL)
    103 		referer = req->referer;
    104 	else
    105 		referer = "-";
    106 
    107 	if (req->agent == NULL)
    108 		req->agent = "-";
    109 
    110 	cn = "-";
    111 	cn_value = NULL;
    112 
    113 	if (req->owner->tls_cert != NULL) {
    114 		if (kore_x509_subject_name(req->owner, &cn_value,
    115 		    KORE_X509_COMMON_NAME_ONLY))
    116 			cn = cn_value;
    117 	}
    118 
    119 	switch (req->owner->family) {
    120 	case AF_INET:
    121 		ptr = inet_ntop(req->owner->family,
    122 		    &(req->owner->addr.ipv4.sin_addr), addr, sizeof(addr));
    123 		break;
    124 	case AF_INET6:
    125 		ptr = inet_ntop(req->owner->family,
    126 		    &(req->owner->addr.ipv6.sin6_addr), addr, sizeof(addr));
    127 		break;
    128 	case AF_UNIX:
    129 		ptr = NULL;
    130 		break;
    131 	default:
    132 		fatal("unknown family %d", req->owner->family);
    133 	}
    134 
    135 	if (ptr == NULL) {
    136 		addr[0] = '-';
    137 		addr[1] = '\0';
    138 	}
    139 
    140 	now = kore_time_ms();
    141 	if ((now - time_cache) >= 1000) {
    142 		time(&curtime);
    143 		tm = localtime(&curtime);
    144 		(void)strftime(tbuf, sizeof(tbuf), "%d/%b/%Y:%H:%M:%S %z", tm);
    145 		time_cache = now;
    146 	}
    147 
    148 	attempts = 0;
    149 	ts.tv_sec = 0;
    150 	ts.tv_nsec = 1000000;
    151 
    152 	for (;;) {
    153 		if (attempts++ > 1000) {
    154 			if (getppid() == 1) {
    155 				if (kill(worker->pid, SIGQUIT) == -1)
    156 					fatal("failed to shutdown");
    157 				return;
    158 			}
    159 
    160 			attempts = 0;
    161 		}
    162 
    163 		accesslog_lock(worker);
    164 
    165 		avail = KORE_ACCESSLOG_BUFLEN - worker->lb.offset;
    166 		if (avail < sizeof(*hdr) + LOG_ENTRY_MINSIZE_GUESS) {
    167 			accesslog_unlock(worker);
    168 			nanosleep(&ts, NULL);
    169 			continue;
    170 		}
    171 
    172 		hdr = (struct kore_alog_header *)
    173 		    (worker->lb.buf + worker->lb.offset);
    174 		worker->lb.offset += sizeof(*hdr);
    175 
    176 		len = snprintf(worker->lb.buf + worker->lb.offset, avail,
    177 		    "%s - %s [%s] \"%s %s %s\" %d %" PRIu64" \"%s\" \"%s\"\n",
    178 		    addr, cn, tbuf, method, req->path, http_version,
    179 		    req->status, req->content_length, referer, req->agent);
    180 		if (len == -1)
    181 			fatal("failed to create log entry");
    182 
    183 		if ((size_t)len >= avail) {
    184 			worker->lb.offset -= sizeof(*hdr);
    185 			accesslog_unlock(worker);
    186 			nanosleep(&ts, NULL);
    187 			continue;
    188 		}
    189 
    190 		if ((size_t)len > USHRT_MAX) {
    191 			kore_log(LOG_WARNING,
    192 			    "log entry length exceeds limit (%d)", len);
    193 			worker->lb.offset -= sizeof(*hdr);
    194 			break;
    195 		}
    196 
    197 		hdr->loglen = len;
    198 		hdr->domain = req->rt->dom->id;
    199 
    200 		worker->lb.offset += (size_t)len;
    201 		break;
    202 	}
    203 
    204 	kore_free(cn_value);
    205 	accesslog_unlock(worker);
    206 }
    207 
    208 void
    209 kore_accesslog_gather(void *arg, u_int64_t now, int force)
    210 {
    211 	int				id;
    212 	struct kore_worker		*kw;
    213 	struct kore_alog_header		*hdr;
    214 	struct kore_domain		*dom;
    215 	size_t				off, remain;
    216 
    217 	if (logbuf == NULL)
    218 		logbuf = kore_buf_alloc(LOGBUF_SIZE);
    219 
    220 	for (id = KORE_WORKER_BASE; id < worker_count; id++) {
    221 		kw = kore_worker_data(id);
    222 
    223 		accesslog_lock(kw);
    224 
    225 		if (force || kw->lb.offset >= KORE_ACCESSLOG_SYNC) {
    226 			kore_buf_append(logbuf, kw->lb.buf, kw->lb.offset);
    227 			kw->lb.offset = 0;
    228 		}
    229 
    230 		accesslog_unlock(kw);
    231 	}
    232 
    233 	if (force || logbuf->offset >= LOGBUF_SIZE) {
    234 		off = 0;
    235 		remain = logbuf->offset;
    236 
    237 		while (remain > 0) {
    238 			if (remain < sizeof(*hdr)) {
    239 				kore_log(LOG_ERR,
    240 				    "invalid log buffer: (%zu remain)", remain);
    241 				break;
    242 			}
    243 
    244 			hdr = (struct kore_alog_header *)(logbuf->data + off);
    245 			off += sizeof(*hdr);
    246 			remain -= sizeof(*hdr);
    247 
    248 			if (hdr->loglen > remain) {
    249 				kore_log(LOG_ERR,
    250 				    "invalid log header: %u (%zu remain)",
    251 				    hdr->loglen, remain);
    252 				break;
    253 			}
    254 
    255 			if ((dom = kore_domain_byid(hdr->domain)) == NULL)
    256 				fatal("unknown domain id %u", hdr->domain);
    257 
    258 			if (dom->logbuf == NULL)
    259 				dom->logbuf = kore_buf_alloc(DOMAIN_LOGBUF_LEN);
    260 
    261 			kore_buf_append(dom->logbuf, &logbuf->data[off],
    262 			    hdr->loglen);
    263 
    264 			off += hdr->loglen;
    265 			remain -= hdr->loglen;
    266 
    267 			accesslog_flush(dom, now, force);
    268 		}
    269 
    270 		kore_buf_reset(logbuf);
    271 	}
    272 
    273 	if (force)
    274 		kore_domain_callback(accesslog_flush_cb);
    275 }
    276 
    277 void
    278 kore_accesslog_run(void *arg, u_int64_t now)
    279 {
    280 	static int	ticks = 0;
    281 
    282 	kore_accesslog_gather(arg, now, ticks++ % 100 ? 0 : 1);
    283 }
    284 
    285 static void
    286 accesslog_flush_cb(struct kore_domain *dom)
    287 {
    288 	accesslog_flush(dom, 0, 1);
    289 }
    290 
    291 static void
    292 accesslog_flush(struct kore_domain *dom, u_int64_t now, int force)
    293 {
    294 	ssize_t		written;
    295 
    296 	if (force && dom->logbuf == NULL)
    297 		return;
    298 
    299 	if (force || dom->logbuf->offset >= DOMAIN_LOGBUF_LEN) {
    300 		written = write(dom->accesslog, dom->logbuf->data,
    301 		    dom->logbuf->offset);
    302 		if (written == -1) {
    303 			if (errno == EINTR)
    304 				return;
    305 			if (dom->logwarn == 0 ||
    306 			    errno != dom->logerr) {
    307 				kore_log(LOG_NOTICE,
    308 				    "error writing log for %s (%s)",
    309 				    dom->domain, errno_s);
    310 				dom->logwarn = now;
    311 				dom->logerr = errno;
    312 			}
    313 			kore_buf_reset(dom->logbuf);
    314 			return;
    315 		}
    316 
    317 		if ((size_t)written != dom->logbuf->offset) {
    318 			kore_log(LOG_ERR, "partial accesslog write for %s",
    319 			    dom->domain);
    320 		}
    321 
    322 		kore_buf_reset(dom->logbuf);
    323 	}
    324 }
    325 
    326 static void
    327 accesslog_lock(struct kore_worker *kw)
    328 {
    329 	for (;;) {
    330 		if (__sync_bool_compare_and_swap(&kw->lb.lock, 0, 1))
    331 			break;
    332 	}
    333 }
    334 
    335 static void
    336 accesslog_unlock(struct kore_worker *kw)
    337 {
    338 	if (!__sync_bool_compare_and_swap(&kw->lb.lock, 1, 0))
    339 		fatal("accesslog_unlock: failed to release");
    340 }