aniani/gophernicus
1
0
Fork 0
mirror of https://github.com/gophernicus/gophernicus.git synced 2024-06-02 06:11:10 +00:00
Code

Rework logging logic

Browse Source 
This commit fixes issue #42 [0].

Debug level messages are masked unless option `-d' (debug) is used. In this
case, all messages are also printed to stderr.

syslog.h is included in the base POSIX only since issue 6 (POSIX:2001) [1].

`LOG_UPTO' is an extension, not defined by POSIX; an implementation is provided
here for platforms where it is missing.

This code is inspired by OpenBSD's httpd(8) logging functions [2].

[0] https://github.com/gophernicus/gophernicus/issues/42
[1] https://pubs.opengroup.org/onlinepubs/9699919799/functions/setlogmask.html
[2] https://cvsweb.openbsd.org/src/usr.sbin/httpd/log.c?rev=1.14&content-type=text/x-cvsweb-markup
This commit is contained in:
Augustin Fabre 2020-04-24 23:13:34 +02:00
parent 8bb9a7cf50
commit 9c0b6a66a4
No known key found for this signature in database
GPG Key ID: 99A01AA293FDA435
9 changed files with 166 additions and 99 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
Makefile
View File

@ -4,7 +4,7 @@ BINARY = $(NAME)
VERSION = 3.1
CODENAME = Dungeon Edition
SOURCES = src/$(NAME).c src/file.c src/menu.c src/string.c src/platform.c src/session.c src/options.c
SOURCES = src/$(NAME).c src/file.c src/menu.c src/string.c src/platform.c src/session.c src/options.c src/log.c
HEADERS = src/files.h src/filetypes.h
OBJECTS = $(SOURCES:.c=.o)
README = README.md

5
gophernicus.1
View File

@ -202,6 +202,11 @@ Print debug output in
.Xr syslog 3
and
.Pa /server-status .
When
.Fl ns
(disable
.Xr syslog 3 )
is used this option has no effect.
.It Fl v
Display version information and build date.
.It Fl b

62
src/file.c
View File

@ -40,7 +40,7 @@ void send_binary_file(state *st)
int fd;
off_t offset = 0;
if (st->debug) syslog(LOG_INFO, "outputting binary file \"%s\"", st->req_realpath);
log_debug("send binary file \"%s\"", st->req_realpath);
if ((fd = open(st->req_realpath, O_RDONLY)) == ERROR) return;
sendfile(1, fd, &offset, st->req_filesize);
@ -52,7 +52,7 @@ void send_binary_file(state *st)
char buf[BUFSIZE];
int bytes;
if (st->debug) syslog(LOG_INFO, "outputting binary file \"%s\"", st->req_realpath);
log_debug("send binary file \"%s\"", st->req_realpath);
if ((fp = fopen(st->req_realpath , "r")) == NULL) return;
while ((bytes = fread(buf, 1, sizeof(buf), fp)) > 0)
@ -72,7 +72,8 @@ void send_text_file(state *st)
char out[BUFSIZE];
int line;
if (st->debug) syslog(LOG_INFO, "outputting text file \"%s\"", st->req_realpath);
log_debug("sending text file \"%s\"", st->req_realpath);
if ((fp = fopen(st->req_realpath , "r")) == NULL) return;
/* Loop through the file line by line */
@ -118,15 +119,13 @@ void url_redirect(state *st)
sstrncmp(dest, "mailto:") != MATCH)
die(st, ERR_ACCESS, "Refusing to HTTP redirect unsafe protocols");
/* Log the redirect */
if (st->opt_syslog) {
syslog(LOG_INFO, "request for \"gopher%s://%s:%i/h%s\" from %s",
(st->server_port == st->server_tls_port ? "s" : ""),
st->server_host,
st->server_port,
st->req_selector,
st->req_remote_addr);
}
log_info("request for \"gopher%s://%s:%i/h%s\" from %s",
st->server_port == st->server_tls_port ? "s" : "",
st->server_host,
st->server_port,
st->req_selector,
st->req_remote_addr);
log_combined(st, HTTP_OK);
/* Output HTML */
@ -155,14 +154,12 @@ void server_status(state *st, shm_state *shm, int shmid)
int sessions;
int i;
/* Log the request */
if (st->opt_syslog) {
syslog(LOG_INFO, "request for \"gopher%s://%s:%i/0" SERVER_STATUS "\" from %s",
(st->server_port == st->server_tls_port ? "s" : ""),
st->server_host,
st->server_port,
st->req_remote_addr);
}
log_info("request for \"gopher%s://%s:%i/0" SERVER_STATUS "\" from %s",
st->server_port == st->server_tls_port ? "s" : "",
st->server_host,
st->server_port,
st->req_remote_addr);
log_combined(st, HTTP_OK);
/* Quit if shared memory isn't initialized yet */
@ -230,14 +227,12 @@ void server_status(state *st, shm_state *shm, int shmid)
*/
void caps_txt(state *st, shm_state *shm)
{
/* Log the request */
if (st->opt_syslog) {
syslog(LOG_INFO, "request for \"gopher%s://%s:%i/0" CAPS_TXT "\" from %s",
(st->server_port == st->server_tls_port ? "s" : ""),
st->server_host,
st->server_port,
st->req_remote_addr);
}
log_info("request for \"gopher%s://%s:%i/0" CAPS_TXT "\" from %s",
st->server_port == st->server_tls_port ? "s" : "",
st->server_host,
st->server_port,
st->req_remote_addr);
log_combined(st, HTTP_OK);
/* Update counters */
@ -369,13 +364,14 @@ static void run_cgi(state *st, char *script, char *arg)
{
if (st->opt_exec) {
/* Setup environment & execute the binary */
if (st->debug) syslog(LOG_INFO, "executing script \"%s\"", script);
/* Setup environment & execute the binary */
log_debug("executing script \"%s\"", script);
setenv_cgi(st, script);
execl(script, script, arg, NULL);
setenv_cgi(st, script);
execl(script, script, arg, NULL);
} else {
log_debug("execution of script \"%s\" blocked by `-nx'", script);
}
else if (st->debug) syslog(LOG_INFO, "script \"%s\" was blocked by -nx", script);
/* Didn't work - die */
die(st, ERR_ACCESS, NULL);

73
src/gophernicus.c
View File

@ -34,11 +34,12 @@
* Libwrap needs these defined
*/
#ifdef HAVE_LIBWRAP
#include <syslog.h>
int allow_severity = LOG_DEBUG;
int deny_severity = LOG_ERR;
#endif
/*
* Print gopher menu line
*/
@ -112,17 +113,12 @@ void footer(state *st)
*/
void die(state *st, const char *message, const char *description)
{
int en = errno;
static const char error_gif[] = ERROR_GIF;
/* Handle NULL description */
if (description == NULL) description = strerror(en);
log_fatal("error \"%s %s\" for request \"%s\" from %s",
message, description ? description : "",
st->req_selector, st->req_remote_addr);
/* Log the error */
if (st->opt_syslog) {
syslog(LOG_ERR, "error \"%s %s\" for request \"%s\" from %s",
message, description, st->req_selector, st->req_remote_addr);
}
log_combined(st, HTTP_404);
/* Handle menu errors */
@ -221,10 +217,8 @@ static void selector_to_path(state *st)
st->rewrite[i].replace,
st->req_selector + strlen(st->rewrite[i].match));
if (st->debug) {
syslog(LOG_INFO, "rewriting selector \"%s\" -> \"%s\"",
st->req_selector, buf);
}
log_debug("rewriting selector \"%s\" -> \"%s\"",
st->req_selector, buf);
sstrlcpy(st->req_selector, buf);
}
@ -530,8 +524,7 @@ int main(int argc, char *argv[])
/* Handle command line arguments */
parse_args(&st, argc, argv);
/* Open syslog() */
if (st.opt_syslog) openlog(self, LOG_PID, LOG_DAEMON);
log_init(st.opt_syslog, st.debug);
#ifdef __OpenBSD__
/* unveil(2) support.
@ -543,8 +536,7 @@ int main(int argc, char *argv[])
if (st.extra_unveil_paths != NULL) {
die(&st, NULL, "-U and executable maps cannot co-exist");
}
if (st.debug)
syslog(LOG_INFO, "executable gophermaps are enabled, no unveil(2)");
log_debug("executable gophermaps are enabled, no unveil(2)");
} else {
if (unveil(st.server_root, "r") == -1)
die(&st, NULL, "unveil");
@ -556,8 +548,7 @@ int main(int argc, char *argv[])
* to unveil it anyway.
*/
if (st.opt_personal_spaces) {
if (st.debug)
syslog(LOG_INFO, "unveiling /etc/pwd.db");
log_debug("unveiling /etc/pwd.db");
if (unveil("/etc/pwd.db", "r") == -1)
die(&st, NULL, "unveil");
}
@ -569,8 +560,7 @@ int main(int argc, char *argv[])
if (*extra_unveil == '\0')
continue; /* empty path */
if (st.debug)
syslog(LOG_INFO, "unveiling extra path: %s\n", extra_unveil);
log_debug("unveiling extra path: %s\n", extra_unveil);
if (unveil(extra_unveil, "r") == -1)
die(&st, NULL, "unveil");
}
@ -582,8 +572,7 @@ int main(int argc, char *argv[])
/* pledge(2) support */
if (st.opt_shm) {
/* pledge(2) never allows shared memory */
if (st.debug)
syslog(LOG_INFO, "shared-memory enabled, can't pledge(2)");
log_debug("shared-memory enabled, can't pledge(2)");
} else {
strlcpy(pledges,
"stdio rpath inet sendfd recvfd proc",
@ -592,21 +581,13 @@ int main(int argc, char *argv[])
/* Executable maps shell-out using popen(3) */
if (st.opt_exec) {
strlcat(pledges, " exec", sizeof(pledges));
if (st.debug) {
syslog(LOG_INFO,
"executable gophermaps enabled, "
"adding 'exec' to pledge(2)");
}
log_debug("executable gophermaps enabled, adding `exec' to pledge(2)");
}
/* Personal spaces require getpwnam(3) and getpwent(3) */
if (st.opt_personal_spaces) {
strlcat(pledges, " getpw", sizeof(pledges));
if (st.debug) {
syslog(LOG_INFO,
"personal gopherspaces enabled, "
"adding 'getpw' to pledge(2)");
}
log_debug("personal gopherspaces enabled, adding `getpw' to pledge(2)");
}
if (pledge(pledges, NULL) == -1)
@ -680,12 +661,12 @@ get_selector:
/* Remove trailing CRLF */
chomp(selector);
if (st.debug) syslog(LOG_INFO, "client sent us \"%s\"", selector);
log_debug("client sent \"%s\"", selector);
/* Handle HAproxy/Stunnel proxy protocol v1 */
#ifdef ENABLE_HAPROXY1
if (sstrncmp(selector, "PROXY TCP") == MATCH && st.opt_proxy) {
if (st.debug) syslog(LOG_INFO, "got proxy protocol header \"%s\"", selector);
log_debug("got proxy protocol header \"%s\"", selector);
sscanf(selector, "PROXY TCP%d %s %s %d %d",
&dummy, remote, local, &dummy, &st.server_port);
@ -716,7 +697,7 @@ get_selector:
printf("+VIEWS:" CRLF " application/gopher+-menu: <512b>" CRLF);
printf("." CRLF);
if (st.debug) syslog(LOG_INFO, "got a request for gopher+ root menu");
log_debug("got a request for gopher+ root menu");
return OK;
}
@ -730,7 +711,7 @@ get_selector:
st.req_protocol = PROTO_HTTP;
if (st.debug) syslog(LOG_INFO, "got HTTP request for \"%s\"", selector);
log_debug("got HTTP request for \"%s\"", selector);
}
/* Save default server_host & fetch session data (including new server_host) */
@ -800,7 +781,7 @@ get_selector:
/* Convert seletor to path & stat() */
selector_to_path(&st);
if (st.debug) syslog(LOG_INFO, "path to resource is \"%s\"", st.req_realpath);
log_debug("path to resource is \"%s\"", st.req_realpath);
if (stat(st.req_realpath, &file) == ERROR) {
@ -858,15 +839,13 @@ get_selector:
#endif
/* Log the request */
if (st.opt_syslog) {
syslog(LOG_INFO, "request for \"gopher%s://%s:%i/%c%s\" from %s",
(st.server_port == st.server_tls_port ? "s" : ""),
st.server_host,
st.server_port,
st.req_filetype,
st.req_selector,
st.req_remote_addr);
}
log_info("request for \"gopher%s://%s:%i/%c%s\" from %s",
st.server_port == st.server_tls_port ? "s" : "",
st.server_host,
st.server_port,
st.req_filetype,
st.req_selector,
st.req_remote_addr);
/* Check file type & act accordingly */
switch (file.st_mode & S_IFMT) {

10
src/gophernicus.h
View File

@ -113,7 +113,6 @@
#include <string.h>
#include <libgen.h>
#include <time.h>
#include <syslog.h>
#include <errno.h>
#include <pwd.h>
#include <limits.h>
@ -250,6 +249,7 @@ size_t strlcat(char *dst, const char *src, size_t siz);
/* Strings */
#define SERVER_SOFTWARE "Gophernicus"
#define SERVER_SOFTWARE_FULL SERVER_SOFTWARE "/" VERSION " (%s)"
#define PROGNAME "gophernicus"
#define HEADER_FORMAT "[%s]"
#define FOOTER_FORMAT "Gophered by Gophernicus/" VERSION " on %s"
@ -484,4 +484,12 @@ void update_shm_session(state *st, shm_state *shm);
/* options.c */
void add_ftype_mapping(state *st, char *suffix);
void parse_args(state *st, int argc, char *argv[]);
/* log.c */
void log_init(int enable, int debug);
void log_fatal(const char *fmt, ...);
void log_warning(const char *fmt, ...);
void log_info(const char *fmt, ...);
void log_debug(const char *fmt, ...);
#endif

88
src/log.c Normal file
View File

@ -0,0 +1,88 @@
#include <stdarg.h>
#include <syslog.h>
#include "gophernicus.h"
#if defined(LOG_UPTO)
#define _LOG_UPTO LOG_UPTO
#else
#define _LOG_UPTO(pri) \
( \
((pri) == LOG_EMERG) ? (LOG_MASK(LOG_EMERG)) : \
((pri) == LOG_ALERT) ? (LOG_MASK(LOG_EMERG) | LOG_MASK(LOG_ALERT)) : \
((pri) == LOG_CRIT) ? (LOG_MASK(LOG_EMERG) | LOG_MASK(LOG_ALERT) | LOG_MASK(LOG_CRIT)) : \
((pri) == LOG_ERR) ? (LOG_MASK(LOG_EMERG) | LOG_MASK(LOG_ALERT) | LOG_MASK(LOG_CRIT) | LOG_MASK(LOG_ERR)) : \
((pri) == LOG_WARNING) ? (LOG_MASK(LOG_EMERG) | LOG_MASK(LOG_ALERT) | LOG_MASK(LOG_CRIT) | LOG_MASK(LOG_ERR) | LOG_MASK(LOG_WARNING)) : \
((pri) == LOG_NOTICE) ? (LOG_MASK(LOG_EMERG) | LOG_MASK(LOG_ALERT) | LOG_MASK(LOG_CRIT) | LOG_MASK(LOG_ERR) | LOG_MASK(LOG_WARNING) | LOG_MASK(LOG_NOTICE)) : \
((pri) == LOG_INFO) ? (LOG_MASK(LOG_EMERG) | LOG_MASK(LOG_ALERT) | LOG_MASK(LOG_CRIT) | LOG_MASK(LOG_ERR) | LOG_MASK(LOG_WARNING) | LOG_MASK(LOG_NOTICE) | LOG_MASK(LOG_INFO)) : \
((pri) == LOG_DEBUG) ? (LOG_MASK(LOG_EMERG) | LOG_MASK(LOG_ALERT) | LOG_MASK(LOG_CRIT) | LOG_MASK(LOG_ERR) | LOG_MASK(LOG_WARNING) | LOG_MASK(LOG_NOTICE) | LOG_MASK(LOG_INFO) | LOG_MASK(LOG_DEBUG)) : \
0)
#endif
static int _enable = 0;
void log_init(int enable, int debug)
{
if (!enable) return;
_enable = enable;
openlog(PROGNAME,
LOG_PID | (debug ? LOG_PERROR : 0),
LOG_DAEMON);
setlogmask(_LOG_UPTO(debug ? LOG_DEBUG : LOG_INFO));
}
static void _vlog(int priority, const char *fmt, va_list ap)
{
char buf[BUFSIZE];
if (!_enable) return;
vsnprintf(buf, sizeof(buf), fmt, ap);
syslog(priority, "%s", buf);
}
static void _log(int priority, const char *fmt, ...)
{
va_list ap;
va_start(ap, fmt);
_vlog(priority, fmt, ap);
va_end(ap);
}
void log_fatal(const char *fmt, ...)
{
va_list ap;
va_start(ap, fmt);
if (errno) {
int en = errno;
char buf[BUFSIZE];
vsnprintf(buf, sizeof(buf), fmt, ap);
_log(LOG_CRIT, "%s (%s)", buf, strerror(en));
} else {
_vlog(LOG_CRIT, fmt, ap);
}
va_end(ap);
}
#define _GOPHERNICUS_MK_LOG_FUNCTION(FCT_LVL, LOG_LVL) \
void FCT_LVL(const char *fmt, ...) \
{ \
va_list ap; \
\
va_start(ap, fmt); \
_vlog(LOG_LVL, fmt, ap); \
va_end(ap); \
}
_GOPHERNICUS_MK_LOG_FUNCTION(log_warning, LOG_WARNING)
_GOPHERNICUS_MK_LOG_FUNCTION(log_info, LOG_INFO)
_GOPHERNICUS_MK_LOG_FUNCTION(log_debug, LOG_DEBUG)
#undef _GOPHERNICUS_MK_LOG_FUNCTION

14
src/menu.c
View File

@ -339,16 +339,10 @@ static int gophermap(state *st, char *mapfile, int depth)
exe = TRUE;
}
/* Debug output */
if (st->debug) {
if (exe) {
if (st->opt_exec)
syslog(LOG_INFO, "parsing executable gophermap \"%s\"", mapfile);
else
syslog(LOG_INFO, "parsing executable gophermap \"%s\" forbidden by -nx", mapfile);
}
else syslog(LOG_INFO, "parsing static gophermap \"%s\"", mapfile);
}
log_debug("parsing %s gophermap \"%s\"%s",
exe ? "executable" : "static",
mapfile,
exe && !st->opt_exec ? ": forbidden by `-nx'" : "");
/* Try to execute or open the mapfile */
if (exe & st->opt_exec) {

7
src/platform.c
View File

@ -280,11 +280,8 @@ void platform(state *st)
machine);
#endif
/* Debug */
if (st->debug) {
syslog(LOG_INFO, "generated platform string \"%s\"",
st->server_platform);
}
log_debug("generated platform string \"%s\"",
st->server_platform);
#else
/* Fallback reply */

4
src/session.c
View File

@ -143,8 +143,8 @@ void update_shm_session(state *st, shm_state *shm)
shm->session[i].hits / st->session_max_hits);
/* Throttle user */
syslog(LOG_INFO, "throttling user from %s for %i seconds",
st->req_remote_addr, delay);
log_info("throttling user from %s for %i seconds",
st->req_remote_addr, delay);
sleep(delay);
}
}