diff --git a/Makefile b/Makefile index 8d8dcac..faa81d1 100644 --- a/Makefile +++ b/Makefile @@ -40,7 +40,7 @@ bin/%.o: src/%.c bin/lib/%.o: src/lib/%.c $(CC) -c -o $@ $(CFLAGS) $< -bin/sesimos: bin/server.o bin/client.o \ +bin/sesimos: bin/server.o bin/client.o bin/logger.o \ bin/lib/cache.o bin/lib/compress.o bin/lib/config.o bin/lib/fastcgi.o bin/lib/geoip.o \ bin/lib/http.o bin/lib/http_static.o bin/lib/rev_proxy.o bin/lib/sock.o bin/lib/uri.o \ bin/lib/utils.o bin/lib/websocket.o @@ -48,26 +48,28 @@ bin/sesimos: bin/server.o bin/client.o \ bin/server.o: src/server.h src/defs.h src/client.h src/lib/cache.h src/lib/config.h src/lib/sock.h \ - src/lib/rev_proxy.h src/lib/geoip.h src/lib/utils.h + src/lib/rev_proxy.h src/lib/geoip.h src/lib/utils.h src/logger.h bin/client.o: src/client.h src/defs.h src/server.h src/lib/utils.h src/lib/config.h src/lib/sock.h \ src/lib/http.h src/lib/rev_proxy.h src/lib/fastcgi.h src/lib/cache.h src/lib/geoip.h src/lib/compress.h \ - src/lib/websocket.h + src/lib/websocket.h src/logger.h -bin/lib/cache.o: src/lib/cache.h src/lib/utils.h src/lib/uri.h src/lib/compress.h +bin/logger.o: src/logger.h + +bin/lib/cache.o: src/lib/cache.h src/lib/utils.h src/lib/uri.h src/lib/compress.h src/logger.h bin/lib/compress.o: src/lib/compress.h -bin/lib/config.o: src/lib/config.h src/lib/utils.h src/lib/uri.h +bin/lib/config.o: src/lib/config.h src/lib/utils.h src/lib/uri.h src/logger.h bin/lib/fastcgi.o: src/lib/fastcgi.h src/server.h src/lib/utils.h src/lib/compress.h src/lib/http.h \ - src/lib/uri.h src/lib/include/fastcgi.h + src/lib/uri.h src/lib/include/fastcgi.h src/logger.h bin/lib/geoip.o: src/lib/geoip.h -bin/lib/http.o: src/lib/http.h src/lib/utils.h src/lib/compress.h src/lib/sock.h +bin/lib/http.o: src/lib/http.h src/lib/utils.h src/lib/compress.h src/lib/sock.h src/logger.h -bin/lib/rev_proxy.o: src/lib/rev_proxy.h src/defs.h src/server.h src/lib/compress.h +bin/lib/rev_proxy.o: src/lib/rev_proxy.h src/defs.h src/server.h src/lib/compress.h src/logger.h bin/lib/sock.o: src/lib/sock.h @@ -75,7 +77,7 @@ bin/lib/uri.o: src/lib/uri.h src/lib/utils.h bin/lib/utils.o: src/lib/utils.h -bin/lib/websocket.o: src/lib/websocket.h src/defs.h src/lib/utils.h src/lib/sock.h +bin/lib/websocket.o: src/lib/websocket.h src/defs.h src/lib/utils.h src/lib/sock.h src/logger.h permit: diff --git a/src/client.c b/src/client.c index 145bd24..9608145 100644 --- a/src/client.c +++ b/src/client.c @@ -9,6 +9,7 @@ #include "defs.h" #include "client.h" #include "server.h" +#include "logger.h" #include "lib/utils.h" #include "lib/config.h" @@ -141,13 +142,13 @@ int client_request_handler(sock *client, unsigned long client_num, unsigned int strcpy(host, host_ptr); } - sprintf(log_req_prefix, "[%6i][%s%*s%s]%s ", getpid(), BLD_STR, INET6_ADDRSTRLEN, host, CLR_STR, log_client_prefix); - log_prefix = log_req_prefix; - print(BLD_STR "%s %s" CLR_STR, req.method, req.uri); + sprintf(log_req_prefix, "[%6i][%s%*s%s]%s", getpid(), BLD_STR, INET6_ADDRSTRLEN, host, CLR_STR, log_client_prefix); + logger_set_prefix(log_req_prefix); + info(BLD_STR "%s %s", req.method, req.uri); conf = get_host_config(host); if (conf == NULL) { - print("Unknown host, redirecting to default"); + info("Unknown host, redirecting to default"); res.status = http_get_status(307); sprintf(buf0, "https://%s%s", DEFAULT_HOST, req.uri); http_add_header_field(&res.hdr, "Location", buf0); @@ -184,7 +185,7 @@ int client_request_handler(sock *client, unsigned long client_num, unsigned int p_len = snprintf(buf1, sizeof(buf1), "https://%s%s", host, buf0); if (p_len < 0 || p_len >= sizeof(buf1)) { res.status = http_get_status(500); - print(ERR_STR "Header field 'Location' too long" CLR_STR); + error("Header field 'Location' too long"); goto respond; } http_add_header_field(&res.hdr, "Location", buf1); @@ -373,7 +374,7 @@ int client_request_handler(sock *client, unsigned long client_num, unsigned int mode = FASTCGI_PHP; } else { res.status = http_get_status(500); - print(ERR_STR "Invalid FastCGI extension: %s" CLR_STR, uri.filename); + error("Invalid FastCGI extension: %s", uri.filename); goto respond; } @@ -475,7 +476,7 @@ int client_request_handler(sock *client, unsigned long client_num, unsigned int } } } else if (conf->type == CONFIG_TYPE_REVERSE_PROXY) { - print("Reverse proxy for " BLD_STR "%s:%i" CLR_STR, conf->rev_proxy.hostname, conf->rev_proxy.port); + info("Reverse proxy for " BLD_STR "%s:%i" CLR_STR, conf->rev_proxy.hostname, conf->rev_proxy.port); http_remove_header_field(&res.hdr, "Date", HTTP_REMOVE_ALL); http_remove_header_field(&res.hdr, "Server", HTTP_REMOVE_ALL); @@ -542,7 +543,7 @@ int client_request_handler(sock *client, unsigned long client_num, unsigned int } */ } else { - print(ERR_STR "Unknown host type: %i" CLR_STR, conf->type); + error("Unknown host type: %i", conf->type); res.status = http_get_status(501); } @@ -637,21 +638,21 @@ int client_request_handler(sock *client, unsigned long client_num, unsigned int clock_gettime(CLOCK_MONOTONIC, &end); const char *location = http_get_header_field(&res.hdr, "Location"); unsigned long micros = (end.tv_nsec - begin.tv_nsec) / 1000 + (end.tv_sec - begin.tv_sec) * 1000000; - print("%s%s%03i %s%s%s (%s)%s", http_get_status_color(res.status), use_rev_proxy ? "-> " : "", res.status->code, - res.status->msg, location != NULL ? " -> " : "", location != NULL ? location : "", - format_duration(micros, buf0), CLR_STR); + info("%s%s%03i %s%s%s (%s)%s", http_get_status_color(res.status), use_rev_proxy ? "-> " : "", res.status->code, + res.status->msg, location != NULL ? " -> " : "", location != NULL ? location : "", + format_duration(micros, buf0), CLR_STR); // TODO access/error log file if (use_rev_proxy == 2) { // WebSocket - print("Upgrading connection to WebSocket connection"); + info("Upgrading connection to WebSocket connection"); ret = ws_handle_connection(client, &rev_proxy); if (ret != 0) { client_keep_alive = 0; close_proxy = 1; } - print("WebSocket connection closed"); + info("WebSocket connection closed"); } else if (strcmp(req.method, "HEAD") != 0) { // default response unsigned long snd_len = 0; @@ -659,7 +660,7 @@ int client_request_handler(sock *client, unsigned long client_num, unsigned int if (msg_buf[0] != 0) { ret = sock_send(client, msg_buf, content_length, 0); if (ret <= 0) { - print(ERR_STR "Unable to send: %s" CLR_STR, sock_strerror(client)); + error("Unable to send: %s", sock_strerror(client)); } snd_len += ret; } else if (file != NULL) { @@ -670,7 +671,7 @@ int client_request_handler(sock *client, unsigned long client_num, unsigned int } ret = sock_send(client, buffer, len, feof(file) ? 0 : MSG_MORE); if (ret <= 0) { - print(ERR_STR "Unable to send: %s" CLR_STR, sock_strerror(client)); + error("Unable to send: %s", sock_strerror(client)); break; } snd_len += ret; @@ -701,13 +702,13 @@ int client_request_handler(sock *client, unsigned long client_num, unsigned int } if (close_proxy && rev_proxy.socket != 0) { - print(BLUE_STR "Closing proxy connection" CLR_STR); + info(BLUE_STR "Closing proxy connection"); sock_close(&rev_proxy); } clock_gettime(CLOCK_MONOTONIC, &end); micros = (end.tv_nsec - begin.tv_nsec) / 1000 + (end.tv_sec - begin.tv_sec) * 1000000; - print("Transfer complete: %s", format_duration(micros, buf0)); + info("Transfer complete: %s", format_duration(micros, buf0)); uri_free(&uri); abort: @@ -732,13 +733,13 @@ int client_connection_handler(sock *client, unsigned long client_num) { sprintf(buf, "dig @%s +short +time=1 -x %s", dns_server, client_addr_str); FILE *dig = popen(buf, "r"); if (dig == NULL) { - print(ERR_STR "Unable to start dig: %s" CLR_STR "\n", strerror(errno)); + error("Unable to start dig: %s", strerror(errno)); goto dig_err; } unsigned long read = fread(buf, 1, sizeof(buf), dig); ret = pclose(dig); if (ret != 0) { - print(ERR_STR "Dig terminated with exit code %i" CLR_STR "\n", ret); + error("Dig terminated with exit code %i", ret); goto dig_err; } char *ptr = memchr(buf, '\n', read); @@ -759,10 +760,10 @@ int client_connection_handler(sock *client, unsigned long client_num) { int gai_error, mmdb_res; MMDB_lookup_result_s result = MMDB_lookup_string(&mmdbs[i], client_addr_str, &gai_error, &mmdb_res); if (mmdb_res != MMDB_SUCCESS) { - print(ERR_STR "Unable to lookup geoip info: %s" CLR_STR "\n", MMDB_strerror(mmdb_res)); + error("Unable to lookup geoip info: %s", MMDB_strerror(mmdb_res)); continue; } else if (gai_error != 0) { - print(ERR_STR "Unable to lookup geoip info" CLR_STR "\n"); + error("Unable to lookup geoip info"); continue; } else if (!result.found_entry) { continue; @@ -771,7 +772,7 @@ int client_connection_handler(sock *client, unsigned long client_num) { MMDB_entry_data_list_s *list; mmdb_res = MMDB_get_entry_data_list(&result.entry, &list); if (mmdb_res != MMDB_SUCCESS) { - print(ERR_STR "Unable to lookup geoip info: %s" CLR_STR "\n", MMDB_strerror(mmdb_res)); + error("Unable to lookup geoip info: %s", MMDB_strerror(mmdb_res)); continue; } @@ -802,9 +803,9 @@ int client_connection_handler(sock *client, unsigned long client_num) { } } - print("Connection accepted from %s %s%s%s[%s]", client_addr_str, client_host_str != NULL ? "(" : "", - client_host_str != NULL ? client_host_str : "", client_host_str != NULL ? ") " : "", - client_cc[0] != 0 ? client_cc : "N/A"); + info("Connection accepted from %s %s%s%s[%s]", client_addr_str, client_host_str != NULL ? "(" : "", + client_host_str != NULL ? client_host_str : "", client_host_str != NULL ? ") " : "", + client_cc[0] != 0 ? client_cc : "N/A"); client_timeout.tv_sec = CLIENT_TIMEOUT; client_timeout.tv_usec = 0; @@ -812,7 +813,7 @@ int client_connection_handler(sock *client, unsigned long client_num) { goto set_timeout_err; if (setsockopt(client->socket, SOL_SOCKET, SO_SNDTIMEO, &client_timeout, sizeof(client_timeout)) < 0) { set_timeout_err: - print(ERR_STR "Unable to set timeout for socket: %s" CLR_STR, strerror(errno)); + error("Unable to set timeout for socket"); return 1; } @@ -826,7 +827,7 @@ int client_connection_handler(sock *client, unsigned long client_num) { client->_errno = errno; client->_ssl_error = ERR_get_error(); if (ret <= 0) { - print(ERR_STR "Unable to perform handshake: %s" CLR_STR, sock_strerror(client)); + error("Unable to perform handshake: %s", sock_strerror(client)); ret = -1; goto close; } @@ -836,21 +837,21 @@ int client_connection_handler(sock *client, unsigned long client_num) { ret = 0; while (ret == 0 && server_keep_alive && req_num < REQ_PER_CONNECTION) { ret = client_request_handler(client, client_num, req_num++); - log_prefix = log_conn_prefix; + logger_set_prefix(log_conn_prefix); } close: sock_close(client); if (rev_proxy.socket != 0) { - print(BLUE_STR "Closing proxy connection" CLR_STR); + info(BLUE_STR "Closing proxy connection"); sock_close(&rev_proxy); } clock_gettime(CLOCK_MONOTONIC, &end); unsigned long micros = (end.tv_nsec - begin.tv_nsec) / 1000 + (end.tv_sec - begin.tv_sec) * 1000000; - print("Connection closed (%s)", format_duration(micros, buf)); + info("Connection closed (%s)", format_duration(micros, buf)); return 0; } @@ -890,10 +891,10 @@ int client_handler(sock *client, unsigned long client_num, struct sockaddr_in6 * ntohs(client_addr->sin6_port), CLR_STR); log_conn_prefix = malloc(256); - sprintf(log_conn_prefix, "[%6i][%*s]%s ", getpid(), INET6_ADDRSTRLEN, server_addr_str, log_client_prefix); - log_prefix = log_conn_prefix; + sprintf(log_conn_prefix, "[%6i][%*s]%s", getpid(), INET6_ADDRSTRLEN, server_addr_str, log_client_prefix); + logger_set_prefix(log_conn_prefix); - print("Started child process with PID %i", getpid()); + info("Started child process with PID %i", getpid()); ret = client_connection_handler(client, client_num); diff --git a/src/lib/cache.c b/src/lib/cache.c index 5acadda..468d99f 100644 --- a/src/lib/cache.c +++ b/src/lib/cache.c @@ -6,6 +6,7 @@ * @date 2020-12-19 */ +#include "../logger.h" #include "cache.h" #include "utils.h" #include "compress.h" @@ -27,11 +28,11 @@ cache_entry *cache; int magic_init(void) { magic = magic_open(MAGIC_MIME); if (magic == NULL) { - fprintf(stderr, ERR_STR "Unable to open magic cookie: %s" CLR_STR "\n", strerror(errno)); + critical("Unable to open magic cookie"); return -1; } if (magic_load(magic, CACHE_MAGIC_FILE) != 0) { - fprintf(stderr, ERR_STR "Unable to load magic cookie: %s" CLR_STR "\n", magic_error(magic)); + critical("Unable to load magic cookie: %s", magic_error(magic)); return -2; } return 0; @@ -42,30 +43,34 @@ void cache_process_term(int _) { } int cache_process(void) { + errno = 0; signal(SIGINT, cache_process_term); signal(SIGTERM, cache_process_term); + logger_set_name("cache"); + int shm_id = shmget(CACHE_SHM_KEY, CACHE_ENTRIES * sizeof(cache_entry), 0); if (shm_id < 0) { - fprintf(stderr, ERR_STR "Unable to create cache shared memory: %s" CLR_STR "\n", strerror(errno)); + critical("Unable to create cache shared memory"); return -1; } shmdt(cache); + errno = 0; void *shm_rw = shmat(shm_id, NULL, 0); if (shm_rw == (void *) -1) { - fprintf(stderr, ERR_STR "Unable to attach cache shared memory (rw): %s" CLR_STR "\n", strerror(errno)); + critical("Unable to attach cache shared memory (rw)"); return -2; } cache = shm_rw; if (mkdir("/var/sesimos/", 0755) < 0 && errno != EEXIST) { - fprintf(stderr, ERR_STR "Unable to create directory '/var/sesimos/': %s" CLR_STR "\n", strerror(errno)); + critical("Unable to create directory '/var/sesimos/'"); return -3; } if (mkdir("/var/sesimos/server/", 0755) < 0 && errno != EEXIST) { - fprintf(stderr, ERR_STR "Unable to create directory '/var/sesimos/server/': %s" CLR_STR "\n", strerror(errno)); + critical("Unable to create directory '/var/sesimos/server/'"); return -3; } @@ -75,6 +80,8 @@ int cache_process(void) { fclose(cache_file); } + errno = 0; + for (int i = 0; i < CACHE_ENTRIES; i++) { cache[i].is_updating = 0; } @@ -93,7 +100,7 @@ int cache_process(void) { for (int i = 0; i < CACHE_ENTRIES; i++) { if (cache[i].filename[0] != 0 && cache[i].meta.etag[0] == 0 && !cache[i].is_updating) { cache[i].is_updating = 1; - fprintf(stdout, "[cache] Hashing file %s\n", cache[i].filename); + info("Hashing file %s", cache[i].filename); ctx = EVP_MD_CTX_new(); EVP_DigestInit(ctx, EVP_sha1()); @@ -106,15 +113,16 @@ int cache_process(void) { if (compress) { sprintf(buf, "%.*s/.sesimos", cache[i].webroot_len, cache[i].filename); if (mkdir(buf, 0755) != 0 && errno != EEXIST) { - fprintf(stderr, ERR_STR "Unable to create directory %s: %s" CLR_STR "\n", buf, strerror(errno)); + error("Unable to create directory %s", buf); goto comp_err; } sprintf(buf, "%.*s/.sesimos/cache", cache[i].webroot_len, cache[i].filename); if (mkdir(buf, 0700) != 0 && errno != EEXIST) { - fprintf(stderr, ERR_STR "Unable to create directory %s: %s" CLR_STR "\n", buf, strerror(errno)); + error("Unable to create directory %s", buf); goto comp_err; } + errno = 0; char *rel_path = cache[i].filename + cache[i].webroot_len + 1; for (int j = 0; j < strlen(rel_path); j++) { @@ -131,22 +139,22 @@ int cache_process(void) { "%.*s/.sesimos/cache/%s.br", cache[i].webroot_len, cache[i].filename, buf); if (p_len_gz < 0 || p_len_gz >= sizeof(filename_comp_gz) || p_len_br < 0 || p_len_br >= sizeof(filename_comp_br)) { - fprintf(stderr, ERR_STR "Unable to open cached file: File name for compressed file too long" CLR_STR "\n"); + error("Unable to open cached file: File name for compressed file too long"); goto comp_err; } - fprintf(stdout, "[cache] Compressing file %s\n", cache[i].filename); + info("Compressing file %s", cache[i].filename); comp_file_gz = fopen(filename_comp_gz, "wb"); comp_file_br = fopen(filename_comp_br, "wb"); if (comp_file_gz == NULL || comp_file_br == NULL) { - fprintf(stderr, ERR_STR "Unable to open cached file: %s" CLR_STR "\n", strerror(errno)); + error("Unable to open cached file"); comp_err: compress = 0; } else { ret = compress_init(&comp_ctx, COMPRESS_GZ | COMPRESS_BR); if (ret != 0) { - fprintf(stderr, ERR_STR "Unable to init compression: %s" CLR_STR "\n", strerror(errno)); + error("Unable to init compression"); compress = 0; fclose(comp_file_gz); fclose(comp_file_br); @@ -177,7 +185,7 @@ int cache_process(void) { compress_free(&comp_ctx); fclose(comp_file_gz); fclose(comp_file_br); - fprintf(stdout, "[cache] Finished compressing file %s\n", cache[i].filename); + info("Finished compressing file %s", cache[i].filename); strcpy(cache[i].meta.filename_comp_gz, filename_comp_gz); strcpy(cache[i].meta.filename_comp_br, filename_comp_br); } else { @@ -193,7 +201,7 @@ int cache_process(void) { sprintf(cache[i].meta.etag + j * 2, "%02x", hash[j]); } fclose(file); - fprintf(stdout, "[cache] Finished hashing file %s\n", cache[i].filename); + info("Finished hashing file %s", cache[i].filename); cache[i].is_updating = 0; cache_changed = 1; } @@ -203,7 +211,7 @@ int cache_process(void) { cache_changed = 0; cache_file = fopen("/var/sesimos/server/cache", "wb"); if (cache_file == NULL) { - fprintf(stderr, ERR_STR "Unable to open cache file: %s" CLR_STR "\n", strerror(errno)); + critical("Unable to open cache file"); return -1; } fwrite(cache, sizeof(cache_entry), CACHE_ENTRIES, cache_file); @@ -217,32 +225,34 @@ int cache_process(void) { } int cache_init(void) { + errno = 0; if (magic_init() != 0) { return -1; } int shm_id = shmget(CACHE_SHM_KEY, CACHE_ENTRIES * sizeof(cache_entry), IPC_CREAT | IPC_EXCL | 0600); if (shm_id < 0) { - fprintf(stderr, ERR_STR "Unable to create cache shared memory: %s" CLR_STR "\n", strerror(errno)); + critical("Unable to create cache shared memory"); return -2; } void *shm = shmat(shm_id, NULL, SHM_RDONLY); if (shm == (void *) -1) { - fprintf(stderr, ERR_STR "Unable to attach cache shared memory (ro): %s" CLR_STR "\n", strerror(errno)); + critical("Unable to attach cache shared memory (ro)"); return -3; } cache = shm; void *shm_rw = shmat(shm_id, NULL, 0); if (shm_rw == (void *) -1) { - fprintf(stderr, ERR_STR "Unable to attach cache shared memory (rw): %s" CLR_STR "\n", strerror(errno)); + critical("Unable to attach cache shared memory (rw)"); return -4; } cache = shm_rw; memset(cache, 0, CACHE_ENTRIES * sizeof(cache_entry)); shmdt(shm_rw); cache = shm; + errno = 0; pid_t pid = fork(); if (pid == 0) { @@ -254,10 +264,10 @@ int cache_init(void) { } } else if (pid > 0) { // parent - fprintf(stderr, "Started child process with PID %i as cache-updater\n", pid); + info("Started child process with PID %i as cache-updater", pid); return pid; } else { - fprintf(stderr, ERR_STR "Unable to create child process: %s" CLR_STR "\n", strerror(errno)); + critical("Unable to create child process"); return -5; } } @@ -265,15 +275,16 @@ int cache_init(void) { int cache_unload(void) { int shm_id = shmget(CACHE_SHM_KEY, 0, 0); if (shm_id < 0) { - fprintf(stderr, ERR_STR "Unable to get cache shared memory id: %s" CLR_STR "\n", strerror(errno)); + critical("Unable to get cache shared memory id"); shmdt(cache); return -1; } else if (shmctl(shm_id, IPC_RMID, NULL) < 0) { - fprintf(stderr, ERR_STR "Unable to configure cache shared memory: %s" CLR_STR "\n", strerror(errno)); + critical("Unable to configure cache shared memory"); shmdt(cache); return -1; } shmdt(cache); + errno = 0; return 0; } @@ -282,7 +293,7 @@ int cache_update_entry(int entry_num, const char *filename, const char *webroot) int shm_id = shmget(CACHE_SHM_KEY, 0, 0); void *shm_rw = shmat(shm_id, NULL, 0); if (shm_rw == (void *) -1) { - print(ERR_STR "Unable to attach cache shared memory (rw): %s" CLR_STR, strerror(errno)); + error("Unable to attach cache shared memory (rw)"); return -1; } cache = shm_rw; @@ -317,6 +328,7 @@ int cache_update_entry(int entry_num, const char *filename, const char *webroot) shmdt(shm_rw); cache = cache_ro; + errno = 0; return 0; } @@ -325,7 +337,7 @@ int cache_filename_comp_invalid(const char *filename) { int shm_id = shmget(CACHE_SHM_KEY, 0, 0); void *shm_rw = shmat(shm_id, NULL, 0); if (shm_rw == (void *) -1) { - print(ERR_STR "Unable to attach cache shared memory (rw): %s" CLR_STR, strerror(errno)); + error("Unable to attach cache shared memory (rw)"); return -1; } cache = shm_rw; diff --git a/src/lib/config.c b/src/lib/config.c index 79cfb79..50db665 100644 --- a/src/lib/config.c +++ b/src/lib/config.c @@ -6,6 +6,7 @@ * @date 2021-01-05 */ +#include "../logger.h" #include "config.h" #include "utils.h" @@ -23,20 +24,20 @@ char geoip_dir[256], dns_server[256]; int config_init(void) { int shm_id = shmget(CONFIG_SHM_KEY, sizeof(t_config), IPC_CREAT | IPC_EXCL | 0640); if (shm_id < 0) { - fprintf(stderr, ERR_STR "Unable to create config shared memory: %s" CLR_STR "\n", strerror(errno)); + critical("Unable to create config shared memory"); return -1; } void *shm = shmat(shm_id, NULL, SHM_RDONLY); if (shm == (void *) -1) { - fprintf(stderr, ERR_STR "Unable to attach config shared memory (ro): %s" CLR_STR "\n", strerror(errno)); + critical("Unable to attach config shared memory (ro)"); return -2; } config = shm; void *shm_rw = shmat(shm_id, NULL, 0); if (shm_rw == (void *) -1) { - fprintf(stderr, ERR_STR "Unable to attach config shared memory (rw): %s" CLR_STR "\n", strerror(errno)); + critical("Unable to attach config shared memory (rw)"); return -3; } config = shm_rw; @@ -49,11 +50,11 @@ int config_init(void) { int config_unload(void) { int shm_id = shmget(CONFIG_SHM_KEY, 0, 0); if (shm_id < 0) { - fprintf(stderr, ERR_STR "Unable to get config shared memory id: %s" CLR_STR "\n", strerror(errno)); + critical("Unable to get config shared memory id"); shmdt(config); return -1; } else if (shmctl(shm_id, IPC_RMID, NULL) < 0) { - fprintf(stderr, ERR_STR "Unable to configure config shared memory: %s" CLR_STR "\n", strerror(errno)); + critical("Unable to configure config shared memory"); shmdt(config); return -1; } @@ -64,7 +65,7 @@ int config_unload(void) { int config_load(const char *filename) { FILE *file = fopen(filename, "r"); if (file == NULL) { - fprintf(stderr, ERR_STR "Unable to open config file: %s" CLR_STR "\n", strerror(errno)); + critical("Unable to open config file"); return -1; } @@ -211,7 +212,7 @@ int config_load(const char *filename) { if (strlen(source) == 0) { err: free(tmp_config); - fprintf(stderr, ERR_STR "Unable to parse config file (line %i)" CLR_STR "\n", line); + critical("Unable to parse config file (line %i)", line); return -2; } @@ -252,14 +253,14 @@ int config_load(const char *filename) { if (!found) { err2: free(tmp_config); - fprintf(stderr, ERR_STR "Unable to parse config file" CLR_STR "\n"); + critical("Unable to parse config file"); return -2; } } int shm_id = shmget(CONFIG_SHM_KEY, 0, 0); if (shm_id < 0) { - fprintf(stderr, ERR_STR "Unable to get config shared memory id: %s" CLR_STR "\n", strerror(errno)); + critical("Unable to get config shared memory id"); shmdt(config); return -3; } @@ -267,7 +268,7 @@ int config_load(const char *filename) { void *shm_rw = shmat(shm_id, NULL, 0); if (shm_rw == (void *) -1) { free(tmp_config); - fprintf(stderr, ERR_STR "Unable to attach config shared memory (rw): %s" CLR_STR "\n", strerror(errno)); + critical("Unable to attach config shared memory (rw)"); return -4; } memcpy(shm_rw, tmp_config, sizeof(t_config)); diff --git a/src/lib/fastcgi.c b/src/lib/fastcgi.c index 402a81d..a9a91b9 100644 --- a/src/lib/fastcgi.c +++ b/src/lib/fastcgi.c @@ -10,6 +10,7 @@ #include "utils.h" #include "compress.h" #include "../server.h" +#include "../logger.h" #include #include @@ -68,7 +69,7 @@ int fastcgi_init(fastcgi_conn *conn, int mode, unsigned int client_num, unsigned int fcgi_sock = socket(AF_UNIX, SOCK_STREAM, 0); if (fcgi_sock < 0) { - print(ERR_STR "Unable to create unix socket: %s" CLR_STR, strerror(errno)); + error("Unable to create unix socket"); return -1; } conn->socket = fcgi_sock; @@ -81,7 +82,7 @@ int fastcgi_init(fastcgi_conn *conn, int mode, unsigned int client_num, unsigned } if (connect(conn->socket, (struct sockaddr *) &sock_addr, sizeof(sock_addr)) < 0) { - print(ERR_STR "Unable to connect to unix socket of FastCGI socket: %s" CLR_STR, strerror(errno)); + error("Unable to connect to unix socket of FastCGI socket"); return -1; } @@ -101,7 +102,7 @@ int fastcgi_init(fastcgi_conn *conn, int mode, unsigned int client_num, unsigned {.roleB1 = (FCGI_RESPONDER >> 8) & 0xFF, .roleB0 = FCGI_RESPONDER & 0xFF, .flags = 0} }; if (send(conn->socket, &begin, sizeof(begin), 0) != sizeof(begin)) { - print(ERR_STR "Unable to send to FastCGI socket: %s" CLR_STR, strerror(errno)); + error("Unable to send to FastCGI socket"); return -2; } @@ -186,7 +187,7 @@ int fastcgi_init(fastcgi_conn *conn, int mode, unsigned int client_num, unsigned header.contentLengthB0 = param_len & 0xFF; memcpy(param_buf, &header, sizeof(header)); if (send(conn->socket, param_buf, param_len + sizeof(header), 0) != param_len + sizeof(header)) { - print(ERR_STR "Unable to send to FastCGI socket: %s" CLR_STR, strerror(errno)); + error("Unable to send to FastCGI socket"); return -2; } @@ -194,7 +195,7 @@ int fastcgi_init(fastcgi_conn *conn, int mode, unsigned int client_num, unsigned header.contentLengthB1 = 0; header.contentLengthB0 = 0; if (send(conn->socket, &header, sizeof(header), 0) != sizeof(header)) { - print(ERR_STR "Unable to send to FastCGI socket: %s" CLR_STR, strerror(errno)); + error("Unable to send to FastCGI socket"); return -2; } @@ -214,7 +215,7 @@ int fastcgi_close_stdin(fastcgi_conn *conn) { }; if (send(conn->socket, &header, sizeof(header), 0) != sizeof(header)) { - print(ERR_STR "Unable to send to FastCGI socket: %s" CLR_STR, strerror(errno)); + error("Unable to send to FastCGI socket"); return -2; } @@ -231,7 +232,7 @@ int fastcgi_php_error(const fastcgi_conn *conn, const char *msg, int msg_len, ch int err = 0; // FIXME *msg is part of a stream, handle fragmented lines while (1) { - int msg_type = 0; + log_lvl_t msg_type = LOG_INFO; int msg_pre_len = 0; ptr1 = strstr(ptr0, "PHP message: "); if (ptr1 == NULL) { @@ -245,16 +246,16 @@ int fastcgi_php_error(const fastcgi_conn *conn, const char *msg, int msg_len, ch } if (len >= 14 && strncmp(ptr0, "PHP Warning: ", 14) == 0) { - msg_type = 1; + msg_type = LOG_WARNING; msg_pre_len = 14; } else if (len >= 18 && strncmp(ptr0, "PHP Fatal error: ", 18) == 0) { - msg_type = 2; + msg_type = LOG_ERROR; msg_pre_len = 18; } else if (len >= 18 && strncmp(ptr0, "PHP Parse error: ", 18) == 0) { - msg_type = 2; + msg_type = LOG_ERROR; msg_pre_len = 18; } else if (len >= 18 && strncmp(ptr0, "PHP Notice: ", 13) == 0) { - msg_type = 1; + msg_type = LOG_NOTICE; msg_pre_len = 13; } @@ -267,7 +268,7 @@ int fastcgi_php_error(const fastcgi_conn *conn, const char *msg, int msg_len, ch if (ptr3 != NULL && (ptr3 - ptr2) < len2) { len2 = (int) (ptr3 - ptr2); } - print("%s%.*s%s", msg_type == 1 ? WRN_STR : msg_type == 2 ? ERR_STR : "", len2, ptr2, CLR_STR); + logmsgf(msg_type, "%.*s", len2, ptr2); if (msg_type == 2 && ptr2 == ptr0) { strcpy_rem_webroot(err_msg, ptr2, len2, conn->webroot); err = 1; @@ -300,12 +301,12 @@ int fastcgi_header(fastcgi_conn *conn, http_res *res, char *err_msg) { if (ret < 0) { res->status = http_get_status(500); sprintf(err_msg, "Unable to communicate with FastCGI socket."); - print(ERR_STR "Unable to receive from FastCGI socket: %s" CLR_STR, strerror(errno)); + error("Unable to receive from FastCGI socket"); return 1; } else if (ret != sizeof(header)) { res->status = http_get_status(500); sprintf(err_msg, "Unable to communicate with FastCGI socket."); - print(ERR_STR "Unable to receive from FastCGI socket" CLR_STR); + error("Unable to receive from FastCGI socket"); return 1; } req_id = (header.requestIdB1 << 8) | header.requestIdB0; @@ -315,13 +316,13 @@ int fastcgi_header(fastcgi_conn *conn, http_res *res, char *err_msg) { if (ret < 0) { res->status = http_get_status(500); sprintf(err_msg, "Unable to communicate with FastCGI socket."); - print(ERR_STR "Unable to receive from FastCGI socket: %s" CLR_STR, strerror(errno)); + error("Unable to receive from FastCGI socket"); free(content); return 1; } else if (ret != (content_len + header.paddingLength)) { res->status = http_get_status(500); sprintf(err_msg, "Unable to communicate with FastCGI socket."); - print(ERR_STR "Unable to receive from FastCGI socket" CLR_STR); + error("Unable to receive from FastCGI socket"); free(content); return 1; } @@ -335,10 +336,10 @@ int fastcgi_header(fastcgi_conn *conn, http_res *res, char *err_msg) { int app_status = (body->appStatusB3 << 24) | (body->appStatusB2 << 16) | (body->appStatusB1 << 8) | body->appStatusB0; if (body->protocolStatus != FCGI_REQUEST_COMPLETE) { - print(ERR_STR "FastCGI protocol error: %i" CLR_STR, body->protocolStatus); + error("FastCGI protocol error: %i", body->protocolStatus); } if (app_status != 0) { - print(ERR_STR "FastCGI app terminated with exit code %i" CLR_STR, app_status); + error("FastCGI app terminated with exit code %i", app_status); } close(conn->socket); conn->socket = 0; @@ -352,7 +353,7 @@ int fastcgi_header(fastcgi_conn *conn, http_res *res, char *err_msg) { } else if (header.type == FCGI_STDOUT) { break; } else { - print(ERR_STR "Unknown FastCGI type: %i" CLR_STR, header.type); + error("Unknown FastCGI type: %i", header.type); } free(content); @@ -369,13 +370,13 @@ int fastcgi_header(fastcgi_conn *conn, http_res *res, char *err_msg) { char *buf = content; unsigned short header_len = conn->out_off; if (header_len <= 0) { - print(ERR_STR "Unable to parse header: End of header not found" CLR_STR); + error("Unable to parse header: End of header not found"); return 1; } for (int i = 0; i < header_len; i++) { if ((buf[i] >= 0x00 && buf[i] <= 0x1F && buf[i] != '\r' && buf[i] != '\n') || buf[i] == 0x7F) { - print(ERR_STR "Unable to parse header: Header contains illegal characters" CLR_STR); + error("Unable to parse header: Header contains illegal characters"); return 2; } } @@ -384,7 +385,7 @@ int fastcgi_header(fastcgi_conn *conn, http_res *res, char *err_msg) { while (header_len != (ptr - buf)) { char *pos0 = strstr(ptr, "\r\n"); if (pos0 == NULL) { - print(ERR_STR "Unable to parse header: Invalid header format" CLR_STR); + error("Unable to parse header: Invalid header format"); return 1; } @@ -413,13 +414,13 @@ int fastcgi_send(fastcgi_conn *conn, sock *client, int flags) { if (flags & FASTCGI_COMPRESS_BR) { flags &= ~FASTCGI_COMPRESS_GZ; if (compress_init(&comp_ctx, COMPRESS_BR) != 0) { - print(ERR_STR "Unable to init brotli: %s" CLR_STR, strerror(errno)); + error("Unable to init brotli"); flags &= ~FASTCGI_COMPRESS_BR; } } else if (flags & FASTCGI_COMPRESS_GZ) { flags &= ~FASTCGI_COMPRESS_BR; if (compress_init(&comp_ctx, COMPRESS_GZ) != 0) { - print(ERR_STR "Unable to init gzip: %s" CLR_STR, strerror(errno)); + error("Unable to init gzip"); flags &= ~FASTCGI_COMPRESS_GZ; } } @@ -434,11 +435,10 @@ int fastcgi_send(fastcgi_conn *conn, sock *client, int flags) { while (1) { ret = recv(conn->socket, &header, sizeof(header), 0); if (ret < 0) { - print(ERR_STR "Unable to receive from FastCGI socket: %s" CLR_STR, strerror(errno)); + error("Unable to receive from FastCGI socket"); return -1; } else if (ret != sizeof(header)) { - print(ERR_STR "Unable to receive from FastCGI socket: received len (%li) != header len (%li)" CLR_STR, - ret, sizeof(header)); + error("Unable to receive from FastCGI socket: received len (%li) != header len (%li)", ret, sizeof(header)); return -1; } @@ -451,7 +451,7 @@ int fastcgi_send(fastcgi_conn *conn, sock *client, int flags) { while (rcv_len < content_len + header.paddingLength) { ret = recv(conn->socket, content + rcv_len, content_len + header.paddingLength - rcv_len, 0); if (ret < 0) { - print(ERR_STR "Unable to receive from FastCGI socket: %s" CLR_STR, strerror(errno)); + error("Unable to receive from FastCGI socket"); free(content); return -1; } @@ -463,10 +463,10 @@ int fastcgi_send(fastcgi_conn *conn, sock *client, int flags) { int app_status = (body->appStatusB3 << 24) | (body->appStatusB2 << 16) | (body->appStatusB1 << 8) | body->appStatusB0; if (body->protocolStatus != FCGI_REQUEST_COMPLETE) { - print(ERR_STR "FastCGI protocol error: %i" CLR_STR, body->protocolStatus); + error("FastCGI protocol error: %i", body->protocolStatus); } if (app_status != 0) { - print(ERR_STR "FastCGI app terminated with exit code %i" CLR_STR, app_status); + error("FastCGI app terminated with exit code %i", app_status); } close(conn->socket); conn->socket = 0; @@ -513,7 +513,7 @@ int fastcgi_send(fastcgi_conn *conn, sock *client, int flags) { } while ((flags & FASTCGI_COMPRESS) && (avail_in != 0 || avail_out != sizeof(comp_out))); if (finish_comp) goto finish; } else { - print(ERR_STR "Unknown FastCGI type: %i" CLR_STR, header.type); + error("Unknown FastCGI type: %i", header.type); } free(content); } @@ -533,11 +533,10 @@ int fastcgi_dump(fastcgi_conn *conn, char *buf, long len) { while (1) { ret = recv(conn->socket, &header, sizeof(header), 0); if (ret < 0) { - print(ERR_STR "Unable to receive from FastCGI socket: %s" CLR_STR, strerror(errno)); + error("Unable to receive from FastCGI socket"); return -1; } else if (ret != sizeof(header)) { - print(ERR_STR "Unable to receive from FastCGI socket: received len (%li) != header len (%li)" CLR_STR, - ret, sizeof(header)); + error("Unable to receive from FastCGI socket: received len (%li) != header len (%li)", ret, sizeof(header)); return -1; } @@ -549,7 +548,7 @@ int fastcgi_dump(fastcgi_conn *conn, char *buf, long len) { while (rcv_len < content_len + header.paddingLength) { ret = recv(conn->socket, content + rcv_len, content_len + header.paddingLength - rcv_len, 0); if (ret < 0) { - print(ERR_STR "Unable to receive from FastCGI socket: %s" CLR_STR, strerror(errno)); + error("Unable to receive from FastCGI socket"); free(content); return -1; } @@ -561,10 +560,10 @@ int fastcgi_dump(fastcgi_conn *conn, char *buf, long len) { int app_status = (body->appStatusB3 << 24) | (body->appStatusB2 << 16) | (body->appStatusB1 << 8) | body->appStatusB0; if (body->protocolStatus != FCGI_REQUEST_COMPLETE) { - print(ERR_STR "FastCGI protocol error: %i" CLR_STR, body->protocolStatus); + error("FastCGI protocol error: %i", body->protocolStatus); } if (app_status != 0) { - print(ERR_STR "FastCGI app terminated with exit code %i" CLR_STR, app_status); + error("FastCGI app terminated with exit code %i", app_status); } close(conn->socket); conn->socket = 0; @@ -579,7 +578,7 @@ int fastcgi_dump(fastcgi_conn *conn, char *buf, long len) { } else if (header.type == FCGI_STDOUT) { ptr += snprintf(ptr, len - (ptr - buf), "%.*s", content_len, content); } else { - print(ERR_STR "Unknown FastCGI type: %i" CLR_STR, header.type); + error("Unknown FastCGI type: %i", header.type); } free(content); } @@ -603,7 +602,7 @@ int fastcgi_receive(fastcgi_conn *conn, sock *client, unsigned long len) { while (rcv_len < len) { ret = sock_recv(client, buf, sizeof(buf), 0); if (ret <= 0) { - print(ERR_STR "Unable to receive: %s" CLR_STR, sock_strerror(client)); + error("Unable to receive: %s", sock_strerror(client)); return -1; } @@ -613,7 +612,7 @@ int fastcgi_receive(fastcgi_conn *conn, sock *client, unsigned long len) { if (send(conn->socket, &header, sizeof(header), 0) != sizeof(header)) goto err; if (send(conn->socket, buf, ret, 0) != ret) { err: - print(ERR_STR "Unable to send to FastCGI socket: %s" CLR_STR, strerror(errno)); + error("Unable to send to FastCGI socket"); return -2; } } diff --git a/src/lib/http.c b/src/lib/http.c index f894530..ab145f9 100644 --- a/src/lib/http.c +++ b/src/lib/http.c @@ -6,6 +6,7 @@ * @date 2020-12-09 */ +#include "../logger.h" #include "http.h" #include "utils.h" #include "compress.h" @@ -87,14 +88,14 @@ void http_free_res(http_res *res) { int http_parse_header_field(http_hdr *hdr, const char *buf, const char *end_ptr, int flags) { if (hdr->last_field_num > hdr->field_num) { - print(ERR_STR "Unable to parse header: Invalid state" CLR_STR); + error("Unable to parse header: Invalid state"); return 3; } char *pos1 = (char *) buf, *pos2 = (char *) end_ptr; if (buf[0] == ' ' || buf[0] == '\t') { if (hdr->last_field_num == -1) { - print(ERR_STR "Unable to parse header" CLR_STR); + error("Unable to parse header"); return 3; } http_field *f = &hdr->fields[(int) hdr->last_field_num]; @@ -107,7 +108,7 @@ int http_parse_header_field(http_hdr *hdr, const char *buf, const char *end_ptr, pos1 = memchr(buf, ':', end_ptr - buf); if (pos1 == NULL) { - print(ERR_STR "Unable to parse header" CLR_STR); + error("Unable to parse header"); return 3; } long len1 = pos1 - buf; @@ -120,7 +121,7 @@ int http_parse_header_field(http_hdr *hdr, const char *buf, const char *end_ptr, int found = http_get_header_field_num_len(hdr, buf, len1); if (!(flags & HTTP_MERGE_FIELDS) || found == -1) { if (http_add_header_field_len(hdr, buf, len1, pos1, len2 < 0 ? 0 : len2) != 0) { - print(ERR_STR "Unable to parse header: Too many header fields" CLR_STR); + error("Unable to parse header: Too many header fields"); return 3; } } else { @@ -147,13 +148,13 @@ int http_receive_request(sock *client, http_req *req) { while (1) { rcv_len = sock_recv(client, buf, CLIENT_MAX_HEADER_SIZE, MSG_PEEK); if (rcv_len <= 0) { - print("Unable to receive http header: %s", sock_strerror(client)); + error("Unable to receive http header: %s", sock_strerror(client)); return -1; } unsigned long header_len = strstr(buf, "\r\n\r\n") - buf + 4; if (header_len <= 0) { - print(ERR_STR "Unable to parse http header: End of header not found" CLR_STR); + error("Unable to parse http header: End of header not found"); return 5; } else { rcv_len = sock_recv(client, buf, header_len, 0); @@ -161,7 +162,7 @@ int http_receive_request(sock *client, http_req *req) { for (int i = 0; i < header_len; i++) { if ((buf[i] >= 0x00 && buf[i] <= 0x1F && buf[i] != '\r' && buf[i] != '\n') || buf[i] == 0x7F) { - print(ERR_STR "Unable to parse http header: Header contains illegal characters" CLR_STR); + error("Unable to parse http header: Header contains illegal characters"); return 4; } } @@ -170,7 +171,7 @@ int http_receive_request(sock *client, http_req *req) { while (header_len > (ptr - buf + 2)) { pos0 = strstr(ptr, "\r\n"); if (pos0 == NULL) { - print(ERR_STR "Unable to parse http header: Invalid header format" CLR_STR); + error("Unable to parse http header: Invalid header format"); return 1; } @@ -179,13 +180,13 @@ int http_receive_request(sock *client, http_req *req) { if (pos1 == NULL) goto err_hdr_fmt; if (pos1 - ptr - 1 >= sizeof(req->method)) { - print(ERR_STR "Unable to parse http header: Method name too long" CLR_STR); + error("Unable to parse http header: Method name too long"); return 2; } for (int i = 0; i < (pos1 - ptr - 1); i++) { if (ptr[i] < 'A' || ptr[i] > 'Z') { - print(ERR_STR "Unable to parse http header: Invalid method" CLR_STR); + error("Unable to parse http header: Invalid method"); return 2; } } @@ -194,12 +195,12 @@ int http_receive_request(sock *client, http_req *req) { pos2 = memchr(pos1, ' ', rcv_len - (pos1 - buf)) + 1; if (pos2 == NULL) { err_hdr_fmt: - print(ERR_STR "Unable to parse http header: Invalid header format" CLR_STR); + error("Unable to parse http header: Invalid header format"); return 1; } if (memcmp(pos2, "HTTP/", 5) != 0 || memcmp(pos2 + 8, "\r\n", 2) != 0) { - print(ERR_STR "Unable to parse http header: Invalid version" CLR_STR); + error("Unable to parse http header: Invalid version"); return 3; } diff --git a/src/lib/rev_proxy.c b/src/lib/rev_proxy.c index 02de458..57a3a29 100644 --- a/src/lib/rev_proxy.c +++ b/src/lib/rev_proxy.c @@ -8,6 +8,7 @@ #include "../defs.h" #include "../server.h" +#include "../logger.h" #include "rev_proxy.h" #include "utils.h" #include "compress.h" @@ -40,7 +41,7 @@ int rev_proxy_request_header(http_req *req, int enc) { } else { p_len = snprintf(buf2, sizeof(buf2), "%s, %s", via, buf1); if (p_len < 0 || p_len >= sizeof(buf2)) { - print(ERR_STR "Header field 'Via' too long" CLR_STR); + error("Header field 'Via' too long"); return -1; } http_remove_header_field(&req->hdr, "Via", HTTP_REMOVE_ALL); @@ -57,7 +58,7 @@ int rev_proxy_request_header(http_req *req, int enc) { client_ipv6 ? "\"[" : "", client_addr_str, client_ipv6 ? "]\"" : "", host, enc ? "https" : "http"); if (p_len < 0 || p_len >= sizeof(buf1)) { - print(ERR_STR "Appended part of header field 'Forwarded' too long" CLR_STR); + error("Appended part of header field 'Forwarded' too long"); return -1; } @@ -66,7 +67,7 @@ int rev_proxy_request_header(http_req *req, int enc) { } else { p_len = snprintf(buf2, sizeof(buf2), "%s, %s", forwarded, buf1); if (p_len < 0 || p_len >= sizeof(buf2)) { - print(ERR_STR "Header field 'Forwarded' too long" CLR_STR); + error("Header field 'Forwarded' too long"); return -1; } http_remove_header_field(&req->hdr, "Forwarded", HTTP_REMOVE_ALL); @@ -134,7 +135,7 @@ int rev_proxy_response_header(http_req *req, http_res *res, host_config *conf) { const char *via = http_get_header_field(&res->hdr, "Via"); p_len = snprintf(buf1, sizeof(buf1), "HTTP/%s %s", req->version, SERVER_NAME); if (p_len < 0 || p_len >= sizeof(buf1)) { - print(ERR_STR "Appended part of header field 'Via' too long" CLR_STR); + error("Appended part of header field 'Via' too long"); return -1; } if (via == NULL) { @@ -142,7 +143,7 @@ int rev_proxy_response_header(http_req *req, http_res *res, host_config *conf) { } else { p_len = snprintf(buf2, sizeof(buf2), "%s, %s", via, buf1); if (p_len < 0 || p_len >= sizeof(buf2)) { - print(ERR_STR "Header field 'Via' too long" CLR_STR); + error("Header field 'Via' too long"); return -1; } http_remove_header_field(&res->hdr, "Via", HTTP_REMOVE_ALL); @@ -190,7 +191,7 @@ int rev_proxy_init(http_req *req, http_res *res, http_status_ctx *ctx, host_conf retry: if (rev_proxy.socket != 0) { - print(BLUE_STR "Closing proxy connection" CLR_STR); + info(BLUE_STR "Closing proxy connection"); sock_close(&rev_proxy); } retry = 0; @@ -198,7 +199,7 @@ int rev_proxy_init(http_req *req, http_res *res, http_status_ctx *ctx, host_conf rev_proxy.socket = socket(AF_INET6, SOCK_STREAM, 0); if (rev_proxy.socket < 0) { - print(ERR_STR "Unable to create socket: %s" CLR_STR, strerror(errno)); + error("Unable to create socket"); res->status = http_get_status(500); ctx->origin = INTERNAL; return -1; @@ -217,7 +218,7 @@ int rev_proxy_init(http_req *req, http_res *res, http_status_ctx *ctx, host_conf if (host_ent == NULL) { res->status = http_get_status(503); ctx->origin = SERVER_REQ; - print(ERR_STR "Unable to connect to server: Name or service not known" CLR_STR); + error("Unable to connect to server: Name or service not known"); sprintf(err_msg, "Unable to connect to server: Name or service not known."); goto proxy_err; } @@ -234,7 +235,7 @@ int rev_proxy_init(http_req *req, http_res *res, http_status_ctx *ctx, host_conf inet_ntop(address.sin6_family, (void *) &address.sin6_addr, buffer, sizeof(buffer)); - print(BLUE_STR "Connecting to " BLD_STR "[%s]:%i" CLR_STR BLUE_STR "..." CLR_STR, buffer, conf->rev_proxy.port); + info(BLUE_STR "Connecting to " BLD_STR "[%s]:%i" CLR_STR BLUE_STR "...", buffer, conf->rev_proxy.port); if (connect(rev_proxy.socket, (struct sockaddr *) &address, sizeof(address)) < 0) { if (errno == ETIMEDOUT || errno == EINPROGRESS) { res->status = http_get_status(504); @@ -246,7 +247,7 @@ int rev_proxy_init(http_req *req, http_res *res, http_status_ctx *ctx, host_conf res->status = http_get_status(500); ctx->origin = INTERNAL; } - print(ERR_STR "Unable to connect to [%s]:%i: %s" CLR_STR, buffer, conf->rev_proxy.port, strerror(errno)); + error("Unable to connect to [%s]:%i: %s", buffer, conf->rev_proxy.port, strerror(errno)); sprintf(err_msg, "Unable to connect to server: %s.", strerror(errno)); goto proxy_err; } @@ -259,7 +260,7 @@ int rev_proxy_init(http_req *req, http_res *res, http_status_ctx *ctx, host_conf rev_proxy_timeout_err: res->status = http_get_status(500); ctx->origin = INTERNAL; - print(ERR_STR "Unable to set timeout for reverse proxy socket: %s" CLR_STR, strerror(errno)); + error("Unable to set timeout for reverse proxy socket"); sprintf(err_msg, "Unable to set timeout for reverse proxy socket: %s", strerror(errno)); goto proxy_err; } @@ -277,14 +278,14 @@ int rev_proxy_init(http_req *req, http_res *res, http_status_ctx *ctx, host_conf if (ret < 0) { res->status = http_get_status(502); ctx->origin = SERVER_REQ; - print(ERR_STR "Unable to perform handshake: %s" CLR_STR, sock_strerror(&rev_proxy)); + error("Unable to perform handshake: %s", sock_strerror(&rev_proxy)); sprintf(err_msg, "Unable to perform handshake: %s.", sock_strerror(&rev_proxy)); goto proxy_err; } } rev_proxy_host = conf->name; - print(BLUE_STR "Established new connection with " BLD_STR "[%s]:%i" CLR_STR, buffer, conf->rev_proxy.port); + info(BLUE_STR "Established new connection with " BLD_STR "[%s]:%i", buffer, conf->rev_proxy.port); rev_proxy: connection = http_get_header_field(&req->hdr, "Connection"); @@ -314,7 +315,7 @@ int rev_proxy_init(http_req *req, http_res *res, http_status_ctx *ctx, host_conf if (ret < 0) { res->status = http_get_status(502); ctx->origin = SERVER_REQ; - print(ERR_STR "Unable to send request to server (1): %s" CLR_STR, sock_strerror(&rev_proxy)); + error("Unable to send request to server (1): %s", sock_strerror(&rev_proxy)); sprintf(err_msg, "Unable to send request to server: %s.", sock_strerror(&rev_proxy)); retry = tries < 4; goto proxy_err; @@ -335,20 +336,20 @@ int rev_proxy_init(http_req *req, http_res *res, http_status_ctx *ctx, host_conf if (ret == -1) { res->status = http_get_status(502); ctx->origin = SERVER_REQ; - print(ERR_STR "Unable to send request to server (2): %s" CLR_STR, sock_strerror(&rev_proxy)); + error("Unable to send request to server (2): %s", sock_strerror(&rev_proxy)); sprintf(err_msg, "Unable to send request to server: %s.", sock_strerror(&rev_proxy)); retry = tries < 4; goto proxy_err; } else if (ret == -2) { res->status = http_get_status(400); ctx->origin = CLIENT_REQ; - print(ERR_STR "Unable to receive request from client: %s" CLR_STR, sock_strerror(client)); + error("Unable to receive request from client: %s", sock_strerror(client)); sprintf(err_msg, "Unable to receive request from client: %s.", sock_strerror(client)); return -1; } res->status = http_get_status(500); ctx->origin = INTERNAL; - print(ERR_STR "Unknown Error" CLR_STR); + error("Unknown Error"); return -1; } @@ -364,7 +365,7 @@ int rev_proxy_init(http_req *req, http_res *res, http_status_ctx *ctx, host_conf res->status = http_get_status(502); ctx->origin = SERVER_RES; } - print(ERR_STR "Unable to receive response from server: %s" CLR_STR, sock_strerror(&rev_proxy)); + error("Unable to receive response from server: %s", sock_strerror(&rev_proxy)); sprintf(err_msg, "Unable to receive response from server: %s.", sock_strerror(&rev_proxy)); retry = tries < 4; goto proxy_err; @@ -376,7 +377,7 @@ int rev_proxy_init(http_req *req, http_res *res, http_status_ctx *ctx, host_conf if (header_len <= 0) { res->status = http_get_status(502); ctx->origin = SERVER_RES; - print(ERR_STR "Unable to parse header: End of header not found" CLR_STR); + error("Unable to parse header: End of header not found"); sprintf(err_msg, "Unable to parser header: End of header not found."); goto proxy_err; } @@ -385,7 +386,7 @@ int rev_proxy_init(http_req *req, http_res *res, http_status_ctx *ctx, host_conf if ((buf[i] >= 0x00 && buf[i] <= 0x1F && buf[i] != '\r' && buf[i] != '\n') || buf[i] == 0x7F) { res->status = http_get_status(502); ctx->origin = SERVER_RES; - print(ERR_STR "Unable to parse header: Header contains illegal characters" CLR_STR); + error("Unable to parse header: Header contains illegal characters"); sprintf(err_msg, "Unable to parse header: Header contains illegal characters."); goto proxy_err; } @@ -397,7 +398,7 @@ int rev_proxy_init(http_req *req, http_res *res, http_status_ctx *ctx, host_conf if (pos0 == NULL) { res->status = http_get_status(502); ctx->origin = SERVER_RES; - print(ERR_STR "Unable to parse header: Invalid header format" CLR_STR); + error("Unable to parse header: Invalid header format"); sprintf(err_msg, "Unable to parse header: Invalid header format."); goto proxy_err; } @@ -405,7 +406,7 @@ int rev_proxy_init(http_req *req, http_res *res, http_status_ctx *ctx, host_conf if (strncmp(ptr, "HTTP/", 5) != 0) { res->status = http_get_status(502); ctx->origin = SERVER_RES; - print(ERR_STR "Unable to parse header: Invalid header format" CLR_STR); + error("Unable to parse header: Invalid header format"); sprintf(err_msg, "Unable to parse header: Invalid header format."); goto proxy_err; } @@ -420,7 +421,7 @@ int rev_proxy_init(http_req *req, http_res *res, http_status_ctx *ctx, host_conf } else if (res->status == NULL) { res->status = http_get_status(502); ctx->origin = SERVER_RES; - print(ERR_STR "Unable to parse header: Invalid or unknown status code" CLR_STR); + error("Unable to parse header: Invalid or unknown status code"); sprintf(err_msg, "Unable to parse header: Invalid or unknown status code."); goto proxy_err; } @@ -429,7 +430,7 @@ int rev_proxy_init(http_req *req, http_res *res, http_status_ctx *ctx, host_conf if (ret != 0) { res->status = http_get_status(502); ctx->origin = SERVER_RES; - print(ERR_STR "Unable to parse header" CLR_STR); + error("Unable to parse header"); sprintf(err_msg, "Unable to parse header."); goto proxy_err; } @@ -464,13 +465,13 @@ int rev_proxy_send(sock *client, unsigned long len_to_send, int flags) { if (flags & REV_PROXY_COMPRESS_BR) { flags &= ~REV_PROXY_COMPRESS_GZ; if (compress_init(&comp_ctx, COMPRESS_BR) != 0) { - print(ERR_STR "Unable to init brotli: %s" CLR_STR, strerror(errno)); + error("Unable to init brotli"); flags &= ~REV_PROXY_COMPRESS_BR; } } else if (flags & REV_PROXY_COMPRESS_GZ) { flags &= ~REV_PROXY_COMPRESS_BR; if (compress_init(&comp_ctx, COMPRESS_GZ) != 0) { - print(ERR_STR "Unable to init gzip: %s" CLR_STR, strerror(errno)); + error("Unable to init gzip"); flags &= ~REV_PROXY_COMPRESS_GZ; } } @@ -481,9 +482,9 @@ int rev_proxy_send(sock *client, unsigned long len_to_send, int flags) { ret = sock_get_chunk_header(&rev_proxy); if (ret < 0) { if (ret == -1) { - print("Unable to receive from server: Malformed chunk header"); + error("Unable to receive from server: Malformed chunk header"); } else { - print("Unable to receive from server: %s", sock_strerror(&rev_proxy)); + error("Unable to receive from server: %s", sock_strerror(&rev_proxy)); } break; } @@ -503,7 +504,7 @@ int rev_proxy_send(sock *client, unsigned long len_to_send, int flags) { unsigned long avail_in, avail_out; ret = sock_recv(&rev_proxy, buffer, CHUNK_SIZE < (len_to_send - snd_len) ? CHUNK_SIZE : len_to_send - snd_len, 0); if (ret <= 0) { - print("Unable to receive from server: %s", sock_strerror(&rev_proxy)); + error("Unable to receive from server: %s", sock_strerror(&rev_proxy)); break; } len = ret; @@ -534,7 +535,7 @@ int rev_proxy_send(sock *client, unsigned long len_to_send, int flags) { if (flags & REV_PROXY_CHUNKED) ret = sock_send(client, "\r\n", 2, 0); if (ret <= 0) { err: - print(ERR_STR "Unable to send: %s" CLR_STR, sock_strerror(client)); + error("Unable to send: %s", sock_strerror(client)); break; } } @@ -551,7 +552,7 @@ int rev_proxy_send(sock *client, unsigned long len_to_send, int flags) { if (flags & REV_PROXY_CHUNKED) { ret = sock_send(client, "0\r\n\r\n", 5, 0); if (ret <= 0) { - print(ERR_STR "Unable to send: %s" CLR_STR, sock_strerror(client)); + error("Unable to send: %s", sock_strerror(client)); return -1; } } diff --git a/src/lib/sock.c b/src/lib/sock.c index 63e3b56..4cfff6c 100644 --- a/src/lib/sock.c +++ b/src/lib/sock.c @@ -188,7 +188,6 @@ long sock_get_chunk_header(sock *s) { char buf[16]; do { - print("debug1"); // TODO remove ret = sock_recv(s, buf, sizeof(buf), MSG_PEEK); if (ret <= 0) return -2; else if (ret < 2) continue; diff --git a/src/lib/utils.c b/src/lib/utils.c index 9f89a49..63e0d5c 100644 --- a/src/lib/utils.c +++ b/src/lib/utils.c @@ -13,8 +13,6 @@ #include -char *log_prefix; - static const char base64_encode_table[64] = "ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz0123456789+/"; static const int base64_mod_table[3] = {0, 2, 1}; diff --git a/src/lib/utils.h b/src/lib/utils.h index ea2bb03..608a60a 100644 --- a/src/lib/utils.h +++ b/src/lib/utils.h @@ -19,19 +19,6 @@ #define HTTP_STR "\x1B[1;31m" #define HTTPS_STR "\x1B[1;32m" -extern char *log_prefix; - - -#define out_1(fmt) fprintf(stdout, "%s" fmt "\n", log_prefix) -#define out_2(fmt, args...) fprintf(stdout, "%s" fmt "\n", log_prefix, args) - -#define out_x(x, arg1, arg2, arg3, arg4, arg5, arg6, arg7, arg8, arg9, FUNC, ...) FUNC - -#define print(...) out_x(, ##__VA_ARGS__, out_2(__VA_ARGS__), out_2(__VA_ARGS__), out_2(__VA_ARGS__), \ - out_2(__VA_ARGS__), out_2(__VA_ARGS__), out_2(__VA_ARGS__), out_2(__VA_ARGS__), \ - out_2(__VA_ARGS__), out_1(__VA_ARGS__)) - - char *format_duration(unsigned long micros, char *buf); int url_encode_component(const void *in, size_t size_in, char *out, size_t size_out); diff --git a/src/lib/websocket.c b/src/lib/websocket.c index c32a1b7..bbb4e46 100644 --- a/src/lib/websocket.c +++ b/src/lib/websocket.c @@ -7,6 +7,7 @@ */ #include "../defs.h" +#include "../logger.h" #include "websocket.h" #include "utils.h" @@ -45,10 +46,10 @@ int ws_recv_frame_header(sock *s, ws_frame *frame) { long ret = sock_recv(s, buf, 2, 0); if (ret < 0) { - print(ERR_STR "Unable to receive from socket: %s" CLR_STR, strerror(errno)); + error("Unable to receive from socket"); return -1; } else if (ret != 2) { - print(ERR_STR "Unable to receive 2 bytes from socket" CLR_STR); + error("Unable to receive 2 bytes from socket"); return -2; } @@ -70,10 +71,10 @@ int ws_recv_frame_header(sock *s, ws_frame *frame) { ret = sock_recv(s, buf, remaining, 0); if (ret < 0) { - print(ERR_STR "Unable to receive from socket: %s" CLR_STR, strerror(errno)); + error("Unable to receive from socket"); return -1; } else if (ret != remaining) { - print(ERR_STR "Unable to receive correct number of bytes from socket" CLR_STR); + error("Unable to receive correct number of bytes from socket"); return -2; } @@ -134,10 +135,10 @@ int ws_send_frame_header(sock *s, ws_frame *frame) { long ret = sock_send(s, buf, ptr - buf, frame->len != 0 ? MSG_MORE : 0); if (ret < 0) { - print(ERR_STR "Unable to send to socket: %s" CLR_STR, strerror(errno)); + error("Unable to send to socket"); return -1; } else if (ret != ptr - buf) { - print(ERR_STR "Unable to send to socket" CLR_STR); + error("Unable to send to socket"); return -2; } @@ -161,13 +162,13 @@ int ws_handle_connection(sock *s1, sock *s2) { if (terminate) { break; } else if (ret < 0) { - print(ERR_STR "Unable to poll sockets: %s" CLR_STR, strerror(errno)); + error("Unable to poll sockets"); return -1; } else if (n_readable == 0) { - print(ERR_STR "Connection timed out" CLR_STR); + error("Connection timed out"); return -2; } else if (n_error > 0) { - print(ERR_STR "Peer closed connection" CLR_STR); + error("Peer closed connection"); return -3; } @@ -176,7 +177,7 @@ int ws_handle_connection(sock *s1, sock *s2) { sock *o = (s == s1) ? s2 : s1; if (ws_recv_frame_header(s, &frame) != 0) return -3; - // print("WebSocket: Peer %s, Opcode=0x%X, Len=%li", (s == s1) ? "1" : "2", frame.opcode, frame.len); + // debug("WebSocket: Peer %s, Opcode=0x%X, Len=%li", (s == s1) ? "1" : "2", frame.opcode, frame.len); if (frame.opcode == 0x8) { n_sock--; @@ -193,10 +194,10 @@ int ws_handle_connection(sock *s1, sock *s2) { if (frame.len > 0) { ret = sock_splice(o, s, buf, sizeof(buf), frame.len); if (ret < 0) { - print(ERR_STR "Unable to forward data in WebSocket: %s" CLR_STR, strerror(errno)); + error("Unable to forward data in WebSocket"); return -4; } else if (ret != frame.len) { - print(ERR_STR "Unable to forward correct number of bytes in WebSocket" CLR_STR); + error("Unable to forward correct number of bytes in WebSocket"); return -4; } } diff --git a/src/logger.c b/src/logger.c new file mode 100644 index 0000000..c43e87a --- /dev/null +++ b/src/logger.c @@ -0,0 +1,257 @@ +/** + * sesimos - secure, simple, modern web server + * @brief Logger + * @file src/logger.h + * @author Lorenz Stechauner + * @date 2022-12-10 + */ + +#include "logger.h" +#include "lib/utils.h" + +#include +#include +#include +#include +#include +#include +#include +#include + +#define LOG_MAX_MSG_SIZE 2048 +#define LOG_BUF_SIZE 16 +#define LOG_NAME_LEN 8 +#define LOG_PREFIX_LEN 256 + +typedef struct { + log_lvl_t lvl; + char name[LOG_NAME_LEN]; + char prefix[LOG_PREFIX_LEN]; + char txt[LOG_MAX_MSG_SIZE]; +} log_msg_t; + +typedef struct { + int rd; + int wr; + log_msg_t msgs[LOG_BUF_SIZE]; +} buf_t; + +static volatile sig_atomic_t logger_alive = 0; +static sem_t sem_buf, sem_buf_free, sem_buf_used; +static buf_t buffer; + +static pthread_key_t key_name = -1, key_prefix = -1; +static char global_name[LOG_NAME_LEN] = "", global_prefix[LOG_PREFIX_LEN] = ""; + +static const char *level_keywords[] = { + "EMERG", + "ALERT", + "CRIT", + "ERROR", + "WARN", + "NOTICE", + "INFO", + "DEBUG" +}; + +void logmsgf(log_lvl_t level, const char *restrict format, ...) { + char buf[256]; + char err_buf[64]; + va_list args; + va_start(args, format); + + const char *color = (level <= LOG_ERROR) ? ERR_STR : ((level <= LOG_WARNING) ? WRN_STR : ""); + if (errno != 0) { + strerror_r(errno, err_buf, sizeof(err_buf)); + snprintf(buf, sizeof(buf), "%s%s: %s" CLR_STR, color, format, err_buf); + } else { + snprintf(buf, sizeof(buf), "%s%s" CLR_STR, color, format); + } + + void *name = pthread_getspecific(key_name); + if (name == NULL && global_name[0] != 0) name = global_name; + void *prefix = pthread_getspecific(key_prefix); + if (prefix == NULL && global_prefix[0] != 0) prefix = global_prefix; + + if (!logger_alive) { + // no logger thread running + // simply write to stdout/stderr without synchronization + FILE *out = (level <= LOG_CRITICAL) ? stderr : stdout; + fprintf(out, "%s[%-6s][%-6s]%s%s ", color, level_keywords[level], (name != NULL) ? (char *) name : "", CLR_STR, (prefix != NULL) ? (char *) prefix : ""); + vfprintf(out, buf, args); + fprintf(out, "\n"); + } else { + // wait for free slot in buffer + try_again_free: + if (sem_wait(&sem_buf_free) != 0) { + if (errno == EINTR) { + goto try_again_free; + } else { + strerror_r(errno, err_buf, sizeof(err_buf)); + fprintf(stderr, "[logger] " ERR_STR "Unable to lock semaphore: %s" CLR_STR "\n", err_buf); + } + // cleanup + va_end(args); + return; + } + + // try to lock buffer + try_again_buf: + if (sem_wait(&sem_buf) != 0) { + if (errno == EINTR) { + goto try_again_buf; + } else { + strerror_r(errno, err_buf, sizeof(err_buf)); + fprintf(stderr, "[logger] " ERR_STR "Unable to lock semaphore: %s" CLR_STR "\n", err_buf); + } + // cleanup + sem_post(&sem_buf_free); + va_end(args); + return; + } + + // write message to buffer + log_msg_t *msg = &buffer.msgs[buffer.rd]; + buffer.rd = (buffer.rd + 1) % LOG_BUF_SIZE; + + vsnprintf(msg->txt, sizeof(msg->txt), buf, args); + msg->lvl = level; + + if (name != NULL) { + snprintf(msg->name, sizeof(msg->name), "%s", (char *) name); + } else { + msg->name[0] = 0; + } + + if (prefix != NULL) { + snprintf(msg->prefix, sizeof(msg->prefix), "%s", (char *) prefix); + } else { + msg->prefix[0] = 0; + } + + // unlock buffer + sem_post(&sem_buf); + + // unlock slot in buffer for logger + sem_post(&sem_buf_used); + } + + // cleanup + va_end(args); +} + +static void logger_destroy(void) { + sem_destroy(&sem_buf); + sem_destroy(&sem_buf_free); + sem_destroy(&sem_buf_used); +} + +static int logger_init(void) { + char err_buf[64]; + int ret; + + // try to initialize all three semaphores + if (sem_init(&sem_buf, 0, 1) != 0 || sem_init(&sem_buf_free, 0, 1) != 0 || sem_init(&sem_buf_used, 0, 0) != 0) { + strerror_r(errno, err_buf, sizeof(err_buf)); + fprintf(stderr, "[logger] " ERR_STR "Unable to initialize semaphore: %s" CLR_STR "\n", err_buf); + logger_destroy(); + return -1; + } + + // initialize read/write heads + buffer.rd = 0; + buffer.wr = 0; + + // initialize thread specific values (keys) + if ((ret = pthread_key_create(&key_name, free)) != 0 || (ret = pthread_key_create(&key_prefix, free)) != 0) { + strerror_r(ret, err_buf, sizeof(err_buf)); + fprintf(stderr, "[logger] " ERR_STR "Unable to initialize thread specific values: %s" CLR_STR "\n", err_buf); + logger_destroy(); + return -1; + } + + return 0; +} + +static int logger_remaining(void) { + int val = 0; + sem_getvalue(&sem_buf_used, &val); + return val; +} + +void logger_set_name(const char *restrict name) { + if (key_name == -1) { + // not initialized + strncpy(global_name, name, sizeof(global_name)); + } else { + char err_buf[64]; + int ret; + void *ptr = pthread_getspecific(key_name); + if (!ptr) { + ptr = malloc(LOG_NAME_LEN); + if ((ret = pthread_setspecific(key_name, ptr)) != 0) { + strerror_r(ret, err_buf, sizeof(err_buf)); + fprintf(stderr, "[logger] " ERR_STR "Unable to set thread specific values: %s" CLR_STR "\n", err_buf); + return; + } + } + strncpy(ptr, name, LOG_NAME_LEN); + } +} + +void logger_set_prefix(const char *restrict prefix) { + if (key_name == -1) { + strncpy(global_prefix, prefix, sizeof(global_prefix)); + } else { + char err_buf[64]; + int ret; + void *ptr = pthread_getspecific(key_name); + if (!ptr) { + ptr = malloc(LOG_PREFIX_LEN); + pthread_setspecific(key_prefix, ptr); + if ((ret = pthread_setspecific(key_prefix, ptr)) != 0) { + strerror_r(ret, err_buf, sizeof(err_buf)); + fprintf(stderr, "[logger] " ERR_STR "Unable to set thread specific values: %s" CLR_STR "\n", err_buf); + return; + } + } + strncpy(ptr, prefix, LOG_PREFIX_LEN); + } +} + +void logger_stop(void) { + logger_alive = 0; +} + +void logger(void) { + char err_buf[64]; + + if (logger_init() != 0) + return; + + logger_set_name("logger"); + logger_alive = 1; + + while (logger_alive || logger_remaining() > 0) { + // wait for buffer to be filled + if (sem_wait(&sem_buf_used) != 0) { + if (errno == EINTR) { + continue; + } else { + strerror_r(errno, err_buf, sizeof(err_buf)); + fprintf(stderr, "[logger] " ERR_STR "Unable to lock semaphore: %s" CLR_STR "\n", err_buf); + break; + } + } + + log_msg_t *msg = &buffer.msgs[buffer.wr]; + buffer.wr = (buffer.wr + 1) % LOG_BUF_SIZE; + + fprintf((msg->lvl <= LOG_CRITICAL) ? stderr : stdout, "[%s]%s %s\n", msg->name, (msg->prefix[0] != 0) ? msg->prefix : "", msg->txt); + + // unlock slot in buffer + sem_post(&sem_buf_free); + } + + logger_destroy(); +} diff --git a/src/logger.h b/src/logger.h new file mode 100644 index 0000000..957bb61 --- /dev/null +++ b/src/logger.h @@ -0,0 +1,40 @@ +/** + * sesimos - secure, simple, modern web server + * @brief Logger (header file) + * @file src/logger.h + * @author Lorenz Stechauner + * @date 2022-12-10 + */ + +#ifndef SESIMOS_LOGGER_H +#define SESIMOS_LOGGER_H + +#define LOG_DEBUG 7 +#define LOG_INFO 6 +#define LOG_NOTICE 5 +#define LOG_WARNING 4 +#define LOG_ERROR 3 +#define LOG_CRITICAL 2 +#define LOG_ALERT 1 + +typedef unsigned char log_lvl_t; + +#define debug(...) logmsgf(LOG_DEBUG, __VA_ARGS__) +#define info(...) logmsgf(LOG_INFO, __VA_ARGS__) +#define notice(...) logmsgf(LOG_NOTICE, __VA_ARGS__) +#define warning(...) logmsgf(LOG_WARNING, __VA_ARGS__) +#define error(...) logmsgf(LOG_ERROR, __VA_ARGS__) +#define critical(...) logmsgf(LOG_CRITICAL, __VA_ARGS__) +#define alert(...) logmsgf(LOG_ALERT, __VA_ARGS__) + +void logmsgf(log_lvl_t level, const char *restrict format, ...); + +void logger_set_name(const char *restrict name); + +void logger_set_prefix(const char *restrict prefix); + +void logger(void); + +void logger_stop(void); + +#endif //SESIMOS_LOGGER_H diff --git a/src/server.c b/src/server.c index 4dc2790..284924a 100644 --- a/src/server.c +++ b/src/server.c @@ -9,6 +9,7 @@ #include "defs.h" #include "server.h" #include "client.h" +#include "logger.h" #include "lib/cache.h" #include "lib/config.h" @@ -58,7 +59,7 @@ static int ssl_servername_cb(SSL *ssl, int *ad, void *arg) { } void destroy(int _) { - fprintf(stderr, "\n" ERR_STR "Terminating forcefully!" CLR_STR "\n"); + error("Terminating forcefully!"); int status = 0; int ret; int kills = 0; @@ -66,11 +67,11 @@ void destroy(int _) { if (children[i] != 0) { ret = waitpid(children[i], &status, WNOHANG); if (ret < 0) { - fprintf(stderr, ERR_STR "Unable to wait for child process (PID %i): %s" CLR_STR "\n", children[i], strerror(errno)); + critical("Unable to wait for child process (PID %i)", children[i]); } else if (ret == children[i]) { children[i] = 0; if (status != 0) { - fprintf(stderr, ERR_STR "Child process with PID %i terminated with exit code %i" CLR_STR "\n", ret, status); + critical("Child process with PID %i terminated with exit code %i", ret, status); } } else { kill(children[i], SIGKILL); @@ -79,7 +80,7 @@ void destroy(int _) { } } if (kills > 0) { - fprintf(stderr, ERR_STR "Killed %i child process(es)" CLR_STR "\n", kills); + critical("Killed %i child process(es)", kills); } cache_unload(); config_unload(); @@ -87,7 +88,7 @@ void destroy(int _) { } void terminate(int _) { - fprintf(stderr, "\nTerminating gracefully...\n"); + notice("Terminating gracefully..."); active = 0; signal(SIGINT, destroy); @@ -105,11 +106,11 @@ void terminate(int _) { if (children[i] != 0) { ret = waitpid(children[i], &status, WNOHANG); if (ret < 0) { - fprintf(stderr, ERR_STR "Unable to wait for child process (PID %i): %s" CLR_STR "\n", children[i], strerror(errno)); + critical("Unable to wait for child process (PID %i)", children[i]); } else if (ret == children[i]) { children[i] = 0; if (status != 0) { - fprintf(stderr, ERR_STR "Child process with PID %i terminated with exit code %i" CLR_STR "\n", ret, status); + critical("Child process with PID %i terminated with exit code %i", ret, status); } } else { kill(children[i], SIGTERM); @@ -119,18 +120,18 @@ void terminate(int _) { } if (wait_num > 0) { - fprintf(stderr, "Waiting for %i child process(es)...\n", wait_num); + info("Waiting for %i child process(es)...", wait_num); } for (int i = 0; i < MAX_CHILDREN; i++) { if (children[i] != 0) { ret = waitpid(children[i], &status, 0); if (ret < 0) { - fprintf(stderr, ERR_STR "Unable to wait for child process (PID %i): %s" CLR_STR "\n", children[i], strerror(errno)); + critical("Unable to wait for child process (PID %i)", children[i]); } else if (ret == children[i]) { children[i] = 0; if (status != 0) { - fprintf(stderr, ERR_STR "Child process with PID %i terminated with exit code %i" CLR_STR "\n", ret, status); + critical("Child process with PID %i terminated with exit code %i", ret, status); } } } @@ -142,10 +143,9 @@ void terminate(int _) { signal(SIGTERM, SIG_IGN); struct timespec ts = {.tv_sec = 0, .tv_nsec = 50000000}; nanosleep(&ts, &ts); - fprintf(stderr, "\nGoodbye\n"); - } else { - fprintf(stderr, "Goodbye\n"); } + + info("Goodbye"); cache_unload(); config_unload(); exit(0); @@ -173,8 +173,10 @@ int main(int argc, const char *argv[]) { {.sin6_family = AF_INET6, .sin6_addr = IN6ADDR_ANY_INIT, .sin6_port = htons(443)} }; + logger_set_name("server"); + if (setvbuf(stdout, NULL, _IOLBF, 0) != 0) { - fprintf(stderr, ERR_STR "Unable to set stdout to line-buffered mode: %s" CLR_STR, strerror(errno)); + critical("Unable to set stdout to line-buffered mode"); return 1; } printf("Sesimos web server " SERVER_VERSION "\n"); @@ -197,13 +199,13 @@ int main(int argc, const char *argv[]) { return 0; } else if (strcmp(arg, "-c") == 0 || strcmp(arg, "--config") == 0) { if (i == argc - 1) { - fprintf(stderr, ERR_STR "Unable to parse argument %s, usage: --config " CLR_STR "\n", arg); + critical("Unable to parse argument %s, usage: --config ", arg); config_unload(); return 1; } config_file = argv[++i]; } else { - fprintf(stderr, ERR_STR "Unable to parse argument '%s'" CLR_STR "\n", arg); + critical("Unable to parse argument '%s'", arg); config_unload(); return 1; } @@ -220,14 +222,14 @@ int main(int argc, const char *argv[]) { sockets[1] = socket(AF_INET6, SOCK_STREAM, 0); if (sockets[1] < 0) { socket_err: - fprintf(stderr, ERR_STR "Unable to create socket: %s" CLR_STR "\n", strerror(errno)); + critical("Unable to create socket"); config_unload(); return 1; } for (int i = 0; i < NUM_SOCKETS; i++) { if (setsockopt(sockets[i], SOL_SOCKET, SO_REUSEADDR, &YES, sizeof(YES)) < 0) { - fprintf(stderr, ERR_STR "Unable to set options for socket %i: %s" CLR_STR "\n", i, strerror(errno)); + critical("Unable to set options for socket %i", i); config_unload(); return 1; } @@ -236,7 +238,7 @@ int main(int argc, const char *argv[]) { if (bind(sockets[0], (struct sockaddr *) &addresses[0], sizeof(addresses[0])) < 0) goto bind_err; if (bind(sockets[1], (struct sockaddr *) &addresses[1], sizeof(addresses[1])) < 0) { bind_err: - fprintf(stderr, ERR_STR "Unable to bind socket to address: %s" CLR_STR "\n", strerror(errno)); + critical("Unable to bind socket to address"); config_unload(); return 1; } @@ -247,7 +249,7 @@ int main(int argc, const char *argv[]) { if (geoip_dir[0] != 0) { DIR *geoip = opendir(geoip_dir); if (geoip == NULL) { - fprintf(stderr, ERR_STR "Unable to open GeoIP dir: %s" CLR_STR "\n", strerror(errno)); + critical("Unable to open GeoIP dir"); config_unload(); return 1; } @@ -256,21 +258,21 @@ int main(int argc, const char *argv[]) { while ((dir = readdir(geoip)) != NULL) { if (strcmp(dir->d_name + strlen(dir->d_name) - 5, ".mmdb") != 0) continue; if (i >= MAX_MMDB) { - fprintf(stderr, ERR_STR "Too many .mmdb files" CLR_STR "\n"); + critical("Too many .mmdb files"); config_unload(); return 1; } sprintf(buf, "%s/%s", geoip_dir, dir->d_name); ret = MMDB_open(buf, 0, &mmdbs[i]); if (ret != MMDB_SUCCESS) { - fprintf(stderr, ERR_STR "Unable to open .mmdb file: %s" CLR_STR "\n", MMDB_strerror(ret)); + critical("Unable to open .mmdb file: %s", MMDB_strerror(ret)); config_unload(); return 1; } i++; } if (i == 0) { - fprintf(stderr, ERR_STR "No .mmdb files found in %s" CLR_STR "\n", geoip_dir); + critical("No .mmdb files found in %s", geoip_dir); config_unload(); return 1; } @@ -304,13 +306,13 @@ int main(int argc, const char *argv[]) { SSL_CTX_set_tlsext_servername_callback(ctx, ssl_servername_cb); if (SSL_CTX_use_certificate_chain_file(ctx, conf->full_chain) != 1) { - fprintf(stderr, ERR_STR "Unable to load certificate chain file: %s: %s" CLR_STR "\n", ERR_reason_error_string(ERR_get_error()), conf->full_chain); + critical("Unable to load certificate chain file: %s: %s", ERR_reason_error_string(ERR_get_error()), conf->full_chain); config_unload(); cache_unload(); return 1; } if (SSL_CTX_use_PrivateKey_file(ctx, conf->priv_key, SSL_FILETYPE_PEM) != 1) { - fprintf(stderr, ERR_STR "Unable to load private key file: %s: %s" CLR_STR "\n", ERR_reason_error_string(ERR_get_error()), conf->priv_key); + critical("Unable to load private key file: %s: %s", ERR_reason_error_string(ERR_get_error()), conf->priv_key); config_unload(); cache_unload(); return 1; @@ -324,7 +326,7 @@ int main(int argc, const char *argv[]) { for (int i = 0; i < NUM_SOCKETS; i++) { if (listen(sockets[i], LISTEN_BACKLOG) < 0) { - fprintf(stderr, ERR_STR "Unable to listen on socket %i: %s" CLR_STR "\n", i, strerror(errno)); + critical("Unable to listen on socket %i", i); config_unload(); cache_unload(); return 1; @@ -336,12 +338,13 @@ int main(int argc, const char *argv[]) { poll_fds[i].events = POLLIN; } - fprintf(stderr, "Ready to accept connections\n"); + errno = 0; + info("Ready to accept connections"); while (active) { ready_sockets_num = poll(poll_fds, NUM_SOCKETS, 1000); if (ready_sockets_num < 0) { - fprintf(stderr, ERR_STR "Unable to poll sockets: %s" CLR_STR "\n", strerror(errno)); + critical("Unable to poll sockets"); terminate(0); return 1; } @@ -350,7 +353,7 @@ int main(int argc, const char *argv[]) { if (poll_fds[i].revents & POLLIN) { client_fd = accept(sockets[i], (struct sockaddr *) &client_addr, &client_addr_len); if (client_fd < 0) { - fprintf(stderr, ERR_STR "Unable to accept connection: %s" CLR_STR "\n", strerror(errno)); + critical("Unable to accept connection"); continue; } @@ -374,7 +377,7 @@ int main(int argc, const char *argv[]) { } } } else { - fprintf(stderr, ERR_STR "Unable to create child process: %s" CLR_STR "\n", strerror(errno)); + critical("Unable to create child process"); } } } @@ -385,11 +388,11 @@ int main(int argc, const char *argv[]) { if (children[i] != 0) { ret = waitpid(children[i], &status, WNOHANG); if (ret < 0) { - fprintf(stderr, ERR_STR "Unable to wait for child process (PID %i): %s" CLR_STR "\n", children[i], strerror(errno)); + critical("Unable to wait for child process (PID %i)", children[i]); } else if (ret == children[i]) { children[i] = 0; if (status != 0) { - fprintf(stderr, ERR_STR "Child process with PID %i terminated with exit code %i" CLR_STR "\n", ret, status); + critical("Child process with PID %i terminated with exit code %i", ret, status); } } }