Simplify logging

For a server, a solid logging-facility is very important.
Reading quark's logs isn't very pleasant, given it prints out
more vocabulary than necessary.
This patch fixes this problem by bringing the logs into a
readable and even parsable form:

-timestamp-   -keyword-  [-message-]

Keywords now take the role as carriers of information.
Instead of writing that we're redirecting, we just
print a line with a status 304 and what the requested
location was. The subsequent 200-response shows the
redirected location.
This also makes clearer what happens in the background.

The tab-separation allows easy parsing.
This commit is contained in:
FRIGN 2014-08-09 18:32:48 +02:00
parent 10416a352b
commit f142064a17

66
quark.c
View file

@ -85,6 +85,7 @@ static char *tstamp(void);
static char location[256]; static char location[256];
static int running = 1; static int running = 1;
static int status;
static char host[NI_MAXHOST]; static char host[NI_MAXHOST];
static char reqbuf[MAXBUFLEN+1]; static char reqbuf[MAXBUFLEN+1];
static char resbuf[MAXBUFLEN+1]; static char resbuf[MAXBUFLEN+1];
@ -118,7 +119,7 @@ atomiclog(int fd, const char *errstr, va_list ap) {
/* assemble the message in buf and write it in one pass /* assemble the message in buf and write it in one pass
to avoid interleaved concurrent writes on a shared fd. */ to avoid interleaved concurrent writes on a shared fd. */
n = snprintf(buf, sizeof buf, "%s: ", tstamp()); n = snprintf(buf, sizeof buf, "%s\t", tstamp());
n += vsnprintf(buf + n, sizeof buf - n, errstr, ap); n += vsnprintf(buf + n, sizeof buf - n, errstr, ap);
if (n >= sizeof buf) if (n >= sizeof buf)
n = sizeof buf - 1; n = sizeof buf - 1;
@ -189,10 +190,10 @@ responsefile(void) {
if ((r = stat(reqbuf, &st)) == -1 || (ffd = open(reqbuf, O_RDONLY)) == -1) { if ((r = stat(reqbuf, &st)) == -1 || (ffd = open(reqbuf, O_RDONLY)) == -1) {
/* file not found */ /* file not found */
logerrmsg("%s requests unknown file %s\n", host, reqbuf);
if (putresentry(HEADER, HttpNotFound, tstamp()) if (putresentry(HEADER, HttpNotFound, tstamp())
|| putresentry(CONTENTTYPE, texthtml)) || putresentry(CONTENTTYPE, texthtml))
return; return;
status = 404;
if (req.type == GET) if (req.type == GET)
writetext("\r\n<html><body>404 Not Found</body></html>\r\n"); writetext("\r\n<html><body>404 Not Found</body></html>\r\n");
} else { } else {
@ -202,6 +203,7 @@ responsefile(void) {
mod[24] = 0; mod[24] = 0;
if (!strcmp(reqmod, mod) && !putresentry(HEADER, HttpNotModified, tstamp())) { if (!strcmp(reqmod, mod) && !putresentry(HEADER, HttpNotModified, tstamp())) {
/* not modified, we're done here*/ /* not modified, we're done here*/
status = 304;
} else { } else {
/* determine mime-type */ /* determine mime-type */
if ((p = strrchr(reqbuf, '.'))) { if ((p = strrchr(reqbuf, '.'))) {
@ -218,6 +220,7 @@ responsefile(void) {
|| putresentry(CONTENTLEN, st.st_size) || putresentry(CONTENTLEN, st.st_size)
|| putresentry(CONTENTTYPE, mimetype)) || putresentry(CONTENTTYPE, mimetype))
return; return;
status = 200;
if (req.type == GET && !writetext("\r\n")) if (req.type == GET && !writetext("\r\n"))
responsefiledata(ffd, st.st_size); responsefiledata(ffd, st.st_size);
} }
@ -232,6 +235,7 @@ responsedirdata(DIR *d) {
if (putresentry(HEADER, HttpOk, tstamp()) if (putresentry(HEADER, HttpOk, tstamp())
|| putresentry(CONTENTTYPE, texthtml)) || putresentry(CONTENTTYPE, texthtml))
return; return;
status = 200;
if (req.type == GET) { if (req.type == GET) {
if (writetext("\r\n<html><body><a href='..'>..</a><br>\r\n")) if (writetext("\r\n<html><body><a href='..'>..</a><br>\r\n"))
return; return;
@ -258,13 +262,14 @@ responsedir(void) {
if ((reqbuf[len - 1] != '/') && (len + 1 < MAXBUFLEN)) { if ((reqbuf[len - 1] != '/') && (len + 1 < MAXBUFLEN)) {
/* add directory terminator if necessary */ /* add directory terminator if necessary */
reqbuf[len++] = '/'; reqbuf[len] = '/';
reqbuf[len] = 0; reqbuf[len + 1] = 0;
logmsg("redirecting %s to %s%s\n", host, location, reqbuf);
if (putresentry(HEADER, HttpMoved, tstamp()) if (putresentry(HEADER, HttpMoved, tstamp())
|| putresentry(LOCATION, location, reqbuf) || putresentry(LOCATION, location, reqbuf)
|| putresentry(CONTENTTYPE, texthtml)) || putresentry(CONTENTTYPE, texthtml))
return; return;
status = 301;
reqbuf[len] = 0;
if (req.type == GET) if (req.type == GET)
writetext("\r\n<html><body>301 Moved Permanently</a></body></html>\r\n"); writetext("\r\n<html><body>301 Moved Permanently</a></body></html>\r\n");
return; return;
@ -301,10 +306,11 @@ responsecgi(void) {
setenv("REQUEST_URI", reqbuf, 1); setenv("REQUEST_URI", reqbuf, 1);
logmsg("CGI SERVER_NAME=%s SCRIPT_NAME=%s REQUEST_URI=%s\n", reqhost, cgi_script, reqbuf); logmsg("CGI SERVER_NAME=%s SCRIPT_NAME=%s REQUEST_URI=%s\n", reqhost, cgi_script, reqbuf);
if (chdir(cgi_dir) == -1) if (chdir(cgi_dir) == -1)
logerrmsg("chdir to cgi directory %s failed: %s\n", cgi_dir, strerror(errno)); logerrmsg("error\tchdir to cgi directory %s failed: %s\n", cgi_dir, strerror(errno));
if ((cgi = popen(cgi_script, "r"))) { if ((cgi = popen(cgi_script, "r"))) {
if (putresentry(HEADER, HttpOk, tstamp())) if (putresentry(HEADER, HttpOk, tstamp()))
return; return;
status = 200;
while ((r = fread(resbuf, 1, MAXBUFLEN, cgi)) > 0) { while ((r = fread(resbuf, 1, MAXBUFLEN, cgi)) > 0) {
if (writedata(resbuf, r)) { if (writedata(resbuf, r)) {
pclose(cgi); pclose(cgi);
@ -313,10 +319,11 @@ responsecgi(void) {
} }
pclose(cgi); pclose(cgi);
} else { } else {
logerrmsg("%s requests %s, but cannot run cgi script %s\n", host, cgi_script, reqbuf); logerrmsg("error\t%s requests %s, but cannot run cgi script %s\n", host, cgi_script, reqbuf);
if (putresentry(HEADER, HttpNotFound, tstamp()) if (putresentry(HEADER, HttpNotFound, tstamp())
|| putresentry(CONTENTTYPE, texthtml)) || putresentry(CONTENTTYPE, texthtml))
return; return;
status = 404;
if (req.type == GET) if (req.type == GET)
writetext("\r\n<html><body>404 Not Found</body></html>\r\n"); writetext("\r\n<html><body>404 Not Found</body></html>\r\n");
} }
@ -329,15 +336,14 @@ response(void) {
for (p = reqbuf; *p; p++) for (p = reqbuf; *p; p++)
if (*p == '\\' || (*p == '/' && *(p + 1) == '.')) { /* don't serve bogus or hidden files */ if (*p == '\\' || (*p == '/' && *(p + 1) == '.')) { /* don't serve bogus or hidden files */
logerrmsg("%s requests bogus or hidden file %s\n", host, reqbuf);
if (putresentry(HEADER, HttpUnauthorized, tstamp()) if (putresentry(HEADER, HttpUnauthorized, tstamp())
|| putresentry(CONTENTTYPE, texthtml)) || putresentry(CONTENTTYPE, texthtml))
return; return;
status = 401;
if (req.type == GET) if (req.type == GET)
writetext("\r\n<html><body>401 Unauthorized</body></html>\r\n"); writetext("\r\n<html><body>401 Unauthorized</body></html>\r\n");
return; return;
} }
logmsg("%s requests: %s\n", host, reqbuf);
if (cgi_mode) { if (cgi_mode) {
responsecgi(); responsecgi();
} else { } else {
@ -377,7 +383,7 @@ request(void) {
/* read request into reqbuf (MAXBUFLEN byte of reqbuf is emergency 0 terminator */ /* read request into reqbuf (MAXBUFLEN byte of reqbuf is emergency 0 terminator */
for (; r > 0 && offset < MAXBUFLEN && (!strstr(reqbuf, "\r\n") || !strstr(reqbuf, "\n"));) { for (; r > 0 && offset < MAXBUFLEN && (!strstr(reqbuf, "\r\n") || !strstr(reqbuf, "\n"));) {
if ((r = read(req.fd, reqbuf + offset, MAXBUFLEN - offset)) == -1) { if ((r = read(req.fd, reqbuf + offset, MAXBUFLEN - offset)) == -1) {
logerrmsg("read: %s\n", strerror(errno)); logerrmsg("error\tread: %s\n", strerror(errno));
return -1; return -1;
} }
offset += r; offset += r;
@ -387,6 +393,7 @@ request(void) {
/* extract host and mod */ /* extract host and mod */
if (getreqentry("Host:", reqhost, LENGTH(reqhost), " \t\r\n") != 0) if (getreqentry("Host:", reqhost, LENGTH(reqhost), " \t\r\n") != 0)
goto invalid_request; goto invalid_request;
if (getreqentry("If-Modified-Since:", reqmod, LENGTH(reqmod), "\r\n") == 1) if (getreqentry("If-Modified-Since:", reqmod, LENGTH(reqmod), "\r\n") == 1)
goto invalid_request; goto invalid_request;
@ -416,7 +423,6 @@ request(void) {
memmove(reqbuf, res, (p - res) + 1); memmove(reqbuf, res, (p - res) + 1);
return 0; return 0;
invalid_request: invalid_request:
logerrmsg("%s performs invalid request %s\n", host, reqbuf);
return -1; return -1;
} }
@ -430,7 +436,7 @@ serve(int fd) {
salen = sizeof sa; salen = sizeof sa;
if ((req.fd = accept(fd, &sa, &salen)) == -1) { if ((req.fd = accept(fd, &sa, &salen)) == -1) {
/* el cheapo socket release */ /* el cheapo socket release */
logerrmsg("cannot accept: %s, sleep a second...\n", strerror(errno)); logerrmsg("info\tcannot accept: %s, sleep a second...\n", strerror(errno));
sleep(1); sleep(1);
continue; continue;
} }
@ -441,17 +447,19 @@ serve(int fd) {
getnameinfo(&sa, salen, host, sizeof host, NULL, 0, NI_NOFQDN); getnameinfo(&sa, salen, host, sizeof host, NULL, 0, NI_NOFQDN);
result = request(); result = request();
shutdown(req.fd, SHUT_RD); shutdown(req.fd, SHUT_RD);
status = -1;
if (result == 0) if (result == 0)
response(); response();
logmsg("%d\t%s\t%s\n", status, host, reqbuf);
shutdown(req.fd, SHUT_WR); shutdown(req.fd, SHUT_WR);
close(req.fd); close(req.fd);
exit(EXIT_SUCCESS); exit(EXIT_SUCCESS);
} else if (result == -1) { } else if (result == -1) {
logerrmsg("fork failed: %s\n", strerror(errno)); logerrmsg("error\tfork failed: %s\n", strerror(errno));
} }
close(req.fd); close(req.fd);
} }
logmsg("shutting down\n"); logmsg("info\tshutting down\n");
} }
void void
@ -459,7 +467,7 @@ sighandler(int sig) {
if (sig == SIGCHLD) { if (sig == SIGCHLD) {
while(0 < waitpid(-1, NULL, WNOHANG)); while(0 < waitpid(-1, NULL, WNOHANG));
} else { } else {
logerrmsg("received signal: %s, closing down\n", strsignal(sig)); logerrmsg("info\tsignal %s, closing down\n", strsignal(sig));
close(fd); close(fd);
running = 0; running = 0;
} }
@ -491,9 +499,9 @@ main(int argc, char *argv[]) {
/* sanity checks */ /* sanity checks */
if (user && !(upwd = getpwnam(user))) if (user && !(upwd = getpwnam(user)))
die("error: invalid user %s\n", user); die("error\tinvalid user %s\n", user);
if (group && !(gpwd = getgrnam(group))) if (group && !(gpwd = getgrnam(group)))
die("error: invalid group %s\n", group); die("error\tinvalid group %s\n", group);
signal(SIGCHLD, sighandler); signal(SIGCHLD, sighandler);
signal(SIGHUP, sighandler); signal(SIGHUP, sighandler);
@ -509,20 +517,20 @@ main(int argc, char *argv[]) {
hints.ai_socktype = SOCK_STREAM; hints.ai_socktype = SOCK_STREAM;
hints.ai_flags = AI_PASSIVE; hints.ai_flags = AI_PASSIVE;
if ((i = getaddrinfo(servername, serverport, &hints, &ai))) if ((i = getaddrinfo(servername, serverport, &hints, &ai)))
die("error: getaddrinfo: %s\n", gai_strerror(i)); die("error\tgetaddrinfo: %s\n", gai_strerror(i));
if ((fd = socket(ai->ai_family, ai->ai_socktype, ai->ai_protocol)) == -1) { if ((fd = socket(ai->ai_family, ai->ai_socktype, ai->ai_protocol)) == -1) {
freeaddrinfo(ai); freeaddrinfo(ai);
die("error: socket: %s\n", strerror(errno)); die("error\tsocket: %s\n", strerror(errno));
} }
if (bind(fd, ai->ai_addr, ai->ai_addrlen) == -1) { if (bind(fd, ai->ai_addr, ai->ai_addrlen) == -1) {
close(fd); close(fd);
freeaddrinfo(ai); freeaddrinfo(ai);
die("error: bind: %s\n", strerror(errno)); die("error\tbind: %s\n", strerror(errno));
} }
if (listen(fd, SOMAXCONN) == -1) { if (listen(fd, SOMAXCONN) == -1) {
close(fd); close(fd);
freeaddrinfo(ai); freeaddrinfo(ai);
die("error: listen: %s\n", strerror(errno)); die("error\tlisten: %s\n", strerror(errno));
} }
if (!strcmp(serverport, "80")) if (!strcmp(serverport, "80"))
@ -532,25 +540,25 @@ main(int argc, char *argv[]) {
if (i >= sizeof location) { if (i >= sizeof location) {
close(fd); close(fd);
freeaddrinfo(ai); freeaddrinfo(ai);
die("error: location too long\n"); die("error\tlocation too long\n");
} }
if (chdir(docroot) == -1) if (chdir(docroot) == -1)
die("error: chdir %s: %s\n", docroot, strerror(errno)); die("error\tchdir %s: %s\n", docroot, strerror(errno));
if (chroot(".") == -1) if (chroot(".") == -1)
die("error: chroot .: %s\n", strerror(errno)); die("error\tchroot .: %s\n", strerror(errno));
if (gpwd && setgid(gpwd->gr_gid) == -1) if (gpwd && setgid(gpwd->gr_gid) == -1)
die("error: cannot set group id\n"); die("error\tcannot set group id\n");
if (upwd && setuid(upwd->pw_uid) == -1) if (upwd && setuid(upwd->pw_uid) == -1)
die("error: cannot set user id\n"); die("error\tcannot set user id\n");
if (getuid() == 0) if (getuid() == 0)
die("error: won't run with root permissions, choose another user\n"); die("error\twon't run with root permissions, choose another user\n");
if (getgid() == 0) if (getgid() == 0)
die("error: won't run with root permissions, choose another group\n"); die("error\twon't run with root permissions, choose another group\n");
logmsg("listening on %s:%s using %s as root directory\n", servername, serverport, docroot); logmsg("ready\t%s:%s\t%s\n", servername, serverport, docroot);
serve(fd); /* main loop */ serve(fd); /* main loop */
freeaddrinfo(ai); freeaddrinfo(ai);