Improved logging system

Signed-off-by: Laurent Bercot <ska@appnovation.com>

10 files changed, 137 insertions, 222 deletions

diff --git a/src/tipideed/cgi.c b/src/tipideed/cgi.c
index 9cd395d..8dde023 100644
--- a/src/tipideed/cgi.c
+++ b/src/tipideed/cgi.c
@@ -139,7 +139,6 @@ static inline int do_nph (tipidee_rql const *rql, char const *const *argv, char
   }
   close(p[1]) ;
   if (fd_move(0, p[0]) == -1) die500sys(rql, 111, "fd_move") ;
-  log_nph(argv, envp) ;
   exec_e(argv, envp) ;
   die500sys(rql, errno == ENOENT ? 127 : 126, "exec nph ", argv[0]) ;
 }
@@ -155,7 +154,6 @@ static inline int run_cgi (tipidee_rql const *rql, char const *const *argv, char
   uint32_t parserstate = 0 ;
   buffer b ;
   char buf[4096] ;
-  log_cgi(argv, envp) ;
   {
     int fd[2] = { 0, 1 } ;
     pid = child_spawn2(argv[0], argv, envp, fd) ;
@@ -178,7 +176,7 @@ static inline int run_cgi (tipidee_rql const *rql, char const *const *argv, char
     {
       kill(pid, SIGTERM) ;
       respond_504(rql) ;
-      if (g.verbosity >= 2) strerr_warnw3x("cgi ", argv[0], " timed out") ;
+      strerr_warnw3x("cgi ", argv[0], " timed out") ;
       break ;
     }
     if (x[1].fd >= 0 && x[1].revents & (IOPAUSE_WRITE | IOPAUSE_EXCEPT))
@@ -186,7 +184,7 @@ static inline int run_cgi (tipidee_rql const *rql, char const *const *argv, char
       size_t len = allwrite(x[1].fd, body + bodyw, bodylen - bodyw) ;
       if (!len)
       {
-        if (g.verbosity) strerr_warnwu2sys("write request body to cgi ", argv[0]) ;
+        strerr_warnwu2sys("write request body to cgi ", argv[0]) ;
         bodyw = bodylen ;
       }
       else bodyw += len ;
@@ -260,7 +258,7 @@ static inline int local_redirect (tipidee_rql *rql, char const *loc, char *uribu
   rql->uri.host = uribuf + n ;
   rql->uri.port = port ;
   rql->uri.https = ishttps ;
-  if (g.verbosity >= 4) strerr_warni4x("cgi ", cginame, ": local redirect to ", rql->uri.path) ;
+  tipidee_log_debug(g.logv, "cgi ", cginame, ": local redirect to ", rql->uri.path) ;
   return 1 ;
 }
 
@@ -361,6 +359,7 @@ static inline int process_cgi_output (tipidee_rql *rql, tipidee_headers const *h
   print_cgi_headers(hdr, rbodylen) ;
   if (buffer_timed_put_g(buffer_1, "\r\n", 2, &deadline) < 2)
     strerr_diefu1sys(111, "write to stdout") ;
+  tipidee_log_answer(g.logv, rql, status, rbodylen) ;
   if (rbodylen)
   {
     if (buffer_timed_put_g(buffer_1, rbody, rbodylen, &deadline) < rbodylen)
@@ -368,15 +367,6 @@ static inline int process_cgi_output (tipidee_rql *rql, tipidee_headers const *h
   }
   if (!buffer_timed_flush_g(buffer_1, &deadline))
     strerr_diefu1sys(111, "write to stdout") ;
-  if (g.verbosity >= 2)
-  {
-    char fmt[UINT_FMT] ;
-    fmt[uint_fmt(fmt, status)] = 0 ;
-    if (status >= 300 && status < 399)
-      strerr_warni6x("cgi ", cginame, ": ", fmt, " client redirect to ", location) ;
-    else
-      strerr_warni6x("cgi ", cginame, ": ", fmt, " ", reason_phrase) ;
-  }
   return 0 ;
 }
 
diff --git a/src/tipideed/deps-exe/tipideed b/src/tipideed/deps-exe/tipideed
index aad1417..a64a8a9 100644
--- a/src/tipideed/deps-exe/tipideed
+++ b/src/tipideed/deps-exe/tipideed
@@ -1,6 +1,5 @@
 cgi.o
 harden.o
-log.o
 options.o
 regular.o
 responses.o
diff --git a/src/tipideed/log.c b/src/tipideed/log.c
deleted file mode 100644
index b08e16f..0000000
--- a/src/tipideed/log.c
+++ /dev/null
@@ -1,65 +0,0 @@
-/* ISC license. */
-
-#include <unistd.h>
-
-#include <skalibs/uint16.h>
-#include <skalibs/types.h>
-#include <skalibs/strerr.h>
-
-#include <tipidee/method.h>
-#include "tipideed-internal.h"
-
-void log_start (void)
-{
-  if (g.verbosity >= 4)
-    strerr_warni7x("new connection", " from ip ", g.sa.s + g.remoteip, " (", g.sa.s + g.remotehost, ") port ", g.sa.s + g.remoteport) ;
-  else if (g.verbosity >= 3)
-    strerr_warni1x("new connection") ;
-}
-
-void log_and_exit (int e)
-{
-  if (g.verbosity >= 3)
-  {
-    char fmt[INT_FMT] ;
-    fmt[int_fmt(fmt, e)] = 0 ;
-    strerr_warni2x("exiting ", fmt) ;
-  }
-  _exit(e) ;
-}
-
-void log_request (tipidee_rql const *rql)
-{
-  if (g.verbosity >= 2)
-  {
-    char fmt[UINT16_FMT] ;
-    if (rql->uri.port) fmt[uint16_fmt(fmt, rql->uri.port)] = 0 ;
-    strerr_warnin(11, "request ", tipidee_method_tostr(rql->m), " for", rql->uri.host ? " host " : "", rql->uri.host ? rql->uri.host : "", rql->uri.port ? " port " : "", rql->uri.port ? fmt : "", " path ", rql->uri.path, rql->uri.query ? " query " : "", rql->uri.query ? rql->uri.query : "") ;
-  }
-}
-
-void log_regular (char const *fn, char const *sizefmt, int ishead, char const *ct)
-{
-  if (g.verbosity >= 2)
-    strerr_warni8x("sending ", ishead ? "headers for " : "", "regular file ", fn, " (", sizefmt, " bytes) with type ", ct) ;
-}
-
-void log_response (char const *ans, char const *fn)
-{
-  if (g.verbosity >= 2)
-    strerr_warni4x("answering ", ans, fn ? " for " : 0, fn) ;
-}
-
-void log_nph (char const *const *argv, char const *const *envp)
-{
-  if (g.verbosity >= 2)
-    strerr_warni3x("running ", "nph ", argv[0]) ;
-  (void)envp ;
-}
-
-void log_cgi (char const *const *argv, char const *const *envp)
-{
-  if (g.verbosity >= 2)
-    strerr_warni3x("running ", "cgi ", argv[0]) ;
-  (void)envp ;
-}
diff --git a/src/tipideed/options.c b/src/tipideed/options.c
index d425943..a023401 100644
--- a/src/tipideed/options.c
+++ b/src/tipideed/options.c
@@ -7,17 +7,19 @@
 #include <skalibs/tai.h>
 #include <skalibs/unix-timed.h>
 
+#include <tipidee/log.h>
 #include <tipidee/response.h>
 #include "tipideed-internal.h"
 
 int respond_options (tipidee_rql const *rql, uint32_t flags)
 {
   tain deadline ;
-  tipidee_response_status_line(buffer_1, rql, "200 OK") ;
+  tipidee_response_status(buffer_1, rql, 200, "OK") ;
   tipidee_response_header_common_put_g(buffer_1, 0) ;
   buffer_putsnoflush(buffer_1, "Content-Length: 0\r\nAllow: GET, HEAD") ;
   if (flags & 1) buffer_putsnoflush(buffer_1, ", POST") ;
   buffer_putnoflush(buffer_1, "\r\n\r\n", 4) ;
+  if (flags & 2) tipidee_log_answer(g.logv, rql, 200, 0) ;
   tain_add_g(&deadline, &g.writetto) ;
   if (!buffer_timed_flush_g(buffer_1, &deadline))
     strerr_diefu1sys(111, "write to stdout") ;
diff --git a/src/tipideed/regular.c b/src/tipideed/regular.c
index 24dc392..845f12b 100644
--- a/src/tipideed/regular.c
+++ b/src/tipideed/regular.c
@@ -15,13 +15,14 @@
 
 #include <tipidee/method.h>
 #include <tipidee/response.h>
+#include <tipidee/log.h>
 #include "tipideed-internal.h"
 
 int respond_regular (tipidee_rql const *rql, char const *fn, struct stat const *st, tipidee_resattr const *ra)
 {
   tain deadline ;
   char fmt[128] ;
-  size_t n = tipidee_response_status_line(buffer_1, rql, "200 OK") ;
+  size_t n = tipidee_response_status(buffer_1, rql, 200, "OK") ;
   n += tipidee_response_header_common_put_g(buffer_1, !g.cont) ;
   {
     size_t l = tipidee_response_header_lastmodified(fmt, 128, st) ;
@@ -33,9 +34,9 @@ int respond_regular (tipidee_rql const *rql, char const *fn, struct stat const *
   fmt[uint64_fmt(fmt, st->st_size)] = 0 ;
   n += buffer_putsnoflush(buffer_1, fmt) ;
   n += buffer_putnoflush(buffer_1, "\r\n\r\n", 4) ;
-  log_regular(fn, fmt, rql->m == TIPIDEE_METHOD_HEAD, ra->content_type) ;
   if (rql->m == TIPIDEE_METHOD_HEAD)
   {
+    tipidee_log_answer(g.logv, rql, 200, st->st_size) ;
     tain_add_g(&deadline, &g.writetto) ;
     if (!buffer_timed_flush_g(buffer_1, &deadline))
       strerr_diefu1sys(111, "write to stdout") ;
@@ -53,6 +54,7 @@ int respond_regular (tipidee_rql const *rql, char const *fn, struct stat const *
       }
       else die500sys(rql, 111, "open ", fn) ;
     }
+    tipidee_log_answer(g.logv, rql, 200, st->st_size) ;
     send_file(fd, st->st_size, fn) ;
     fd_close(fd) ;
   }
@@ -63,14 +65,14 @@ int respond_304 (tipidee_rql const *rql, char const *fn, struct stat const *st)
 {
   tain deadline ;
   char fmt[128] ;
-  size_t n = tipidee_response_status_line(buffer_1, rql, "304 Not Modified") ;
+  size_t n = tipidee_response_status(buffer_1, rql, 304, "Not Modified") ;
   n += tipidee_response_header_common_put_g(buffer_1, !g.cont) ;
   {
     size_t l = tipidee_response_header_lastmodified(fmt, 128, st) ;
     if (l) n += buffer_putnoflush(buffer_1, fmt, l) ;
   }
   n += buffer_putnoflush(buffer_1, "\r\n", 2) ;
-  log_response("304", fn) ;
+  tipidee_log_answer(g.logv, rql, 304, 0) ;
   tain_add_g(&deadline, &g.writetto) ;
   if (!buffer_timed_flush_g(buffer_1, &deadline))
     strerr_diefu1sys(111, "write to stdout") ;
diff --git a/src/tipideed/responses.c b/src/tipideed/responses.c
index 8c6f1f5..e5706e2 100644
--- a/src/tipideed/responses.c
+++ b/src/tipideed/responses.c
@@ -9,63 +9,64 @@
 #include <skalibs/unix-timed.h>
 
 #include <tipidee/rql.h>
+#include <tipidee/log.h>
 #include <tipidee/response.h>
 
 #include "tipideed-internal.h"
 
-void response_error (tipidee_rql const *rql, char const *rsl, char const *text, int doclose)
+void response_error (tipidee_rql const *rql, unsigned int status, char const *rsl, char const *text, uint32_t options)
 {
   tain deadline ;
-  char ans[4] = "???" ;
-  memcpy(ans, rsl, 3) ;
-  tipidee_response_error(buffer_1, rql, rsl, text, doclose || !g.cont) ;
+  tipidee_response_error(buffer_1, rql, status, rsl, text, options & 1 || !g.cont) ;
   tain_add_g(&deadline, &g.writetto) ;
-  log_response(ans, 0) ;
+  if (!(options & 2)) tipidee_log_answer(g.logv, rql, status, 0) ;
   if (!buffer_timed_flush_g(buffer_1, &deadline))
     strerr_diefu1sys(111, "write to stdout") ;
 }
 
-void response_error_and_exit (tipidee_rql const *rql, char const *rsl, char const *text)
+void response_error_and_exit (tipidee_rql const *rql, unsigned int status, char const *rsl, char const *text, uint32_t options)
 {
-  response_error(rql, rsl, text, 1) ;
-  log_and_exit(0) ;
+  response_error(rql, status, rsl, text, options | 1) ;
+  tipidee_log_exit(g.logv, 0) ;
+  _exit(0) ;
 }
 
-void response_error_and_die (tipidee_rql const *rql, int e, char const *rsl, char const *text, char const *const *v, unsigned int n, int dosys)
+void response_error_and_die (tipidee_rql const *rql, int e, unsigned int status, char const *rsl, char const *text, char const *const *v, unsigned int n, uint32_t options)
 {
-  response_error(rql, rsl, text, 1) ;
-  if (dosys) strerr_dievsys(e, v, n) ;
+  response_error(rql, status, rsl, text, options | 1) ;
+  if (options & 1) strerr_dievsys(e, v, n) ;
   else strerr_diev(e, v, n) ;
 }
 
 void exit_405 (tipidee_rql const *rql, uint32_t options)
 {
   tain deadline ;
-  tipidee_response_status_line(buffer_1, rql, "405 Method Not Allowed") ;
+  tipidee_response_status(buffer_1, rql, 405, "Method Not Allowed") ;
   tipidee_response_header_common_put_g(buffer_1, 1) ;
   buffer_putsnoflush(buffer_1, "Allow: GET, HEAD") ;
   if (options & 1) buffer_putsnoflush(buffer_1, ", POST") ;
   buffer_putnoflush(buffer_1, "\r\n\r\n", 4) ;
+  if (!(options & 2)) tipidee_log_answer(g.logv, rql, 405, 0) ;
   tain_add_g(&deadline, &g.writetto) ;
   if (!buffer_timed_flush_g(buffer_1, &deadline))
     strerr_diefu1sys(111, "write to stdout") ;
-  log_and_exit(0) ;
+  tipidee_log_exit(g.logv, 0) ;
+  _exit(0) ;
 }
 
 void respond_30x (tipidee_rql const *rql, tipidee_redirection const *rd)
 {
-  static char const *rsl[4] = { "307 Temporary Redirect", "308 Permanent Redirect", "302 Found", "301 Moved Permanently" } ;
+  static unsigned int const status[4] = { 307, 308, 302, 301 } ;
+  static char const *const reason[4] = { "Temporary Redirect", "Permanent Redirect", "Found", "Moved Permanently" } ;
   tain deadline ;
-  char ans[4] = "30x" ;
-  memcpy(ans, rsl[rd->type], 3) ;
-  tipidee_response_status_line(buffer_1, rql, rsl[rd->type]) ;
+  tipidee_response_status(buffer_1, rql, status[rd->type], reason[rd->type]) ;
   tipidee_response_header_common_put_g(buffer_1, 0) ;
   buffer_putsnoflush(buffer_1, "Content-Length: 0\r\nLocation: ") ;
   buffer_putsnoflush(buffer_1, rd->location) ;
   if (rd->sub) buffer_putsnoflush(buffer_1, rd->sub) ;
   buffer_putnoflush(buffer_1, "\r\n\r\n", 4) ;
+  tipidee_log_answer(g.logv, rql, status[rd->type], 0) ;
   tain_add_g(&deadline, &g.writetto) ;
-  log_response(ans, 0) ;
   if (!buffer_timed_flush_g(buffer_1, &deadline))
     strerr_diefu1sys(111, "write to stdout") ;
 }
diff --git a/src/tipideed/send_file.c b/src/tipideed/send_file.c
index 2aeec65..6d97167 100644
--- a/src/tipideed/send_file.c
+++ b/src/tipideed/send_file.c
@@ -68,8 +68,7 @@ void send_file (int fd, uint64_t n, char const *fn)
     else if (si.n > n)
     {
       si.n = n ;
-      if (g.verbosity >= 2)
-        strerr_warnw2x("serving elongated file: ", fn) ;
+      strerr_warnw2x("serving elongated file: ", fn) ;
     }
     n -= si.n ;
     if (!n) si.last = 1 ;
@@ -109,8 +108,7 @@ void send_file (int fd, uint64_t n, char const *fn)
   if (r > n)
   {
     r = n ;
-    if (g.verbosity >= 2)
-      strerr_warnw2x("serving elongated file: ", fn) ;
+    strerr_warnw2x("serving elongated file: ", fn) ;
   }
   buffer_wseek(buffer_1, r) ;
   n -= r ;
diff --git a/src/tipideed/tipideed-internal.h b/src/tipideed/tipideed-internal.h
index 770596b..fe01152 100644
--- a/src/tipideed/tipideed-internal.h
+++ b/src/tipideed/tipideed-internal.h
@@ -18,26 +18,11 @@
 #define URI_BUFSIZE 4096
 #define HDR_BUFSIZE 8192
 
-typedef struct tipidee_resattr_s tipidee_resattr, *tipidee_resattr_ref ;
-struct tipidee_resattr_s
-{
-  char const *content_type ;
-  uint32_t iscgi : 1 ;
-  uint32_t isnph : 1 ;
-} ;
-#define TIPIDEE_RESATTR_ZERO { .content_type = 0, .iscgi = 0, .isnph = 0 }
-
 struct global_s
 {
   tipidee_conf conf ;
   stralloc sa ;
   size_t envlen ;
-  size_t localip ;
-  size_t localport ;
-  size_t localhost ;
-  size_t remoteip ;
-  size_t remoteport ;
-  size_t remotehost ;
   size_t cwdlen ;
   size_t indexlen ;
   tain readtto ;
@@ -46,11 +31,11 @@ struct global_s
   char const *defaulthost ;
   char const *indexnames[16] ;
   int p[2] ;
+  uint32_t logv ;
   uint32_t maxrqbody ;
   uint32_t maxcgibody ;
   uint16_t defaultport ;
   uint16_t indexn : 4 ;
-  uint16_t verbosity : 3 ;
   uint16_t cont : 2 ;
   uint16_t ssl : 1 ;
 } ;
@@ -59,12 +44,6 @@ struct global_s
   .conf = TIPIDEE_CONF_ZERO, \
   .sa = STRALLOC_ZERO, \
   .envlen = 0, \
-  .localip = 0, \
-  .localport = 0, \
-  .localhost = 0, \
-  .remoteip = 0, \
-  .remoteport = 0, \
-  .remotehost = 0, \
   .cwdlen = 1, \
   .indexlen = 0, \
   .readtto = TAIN_ZERO, \
@@ -73,11 +52,11 @@ struct global_s
   .defaulthost = "@", \
   .indexnames = { 0 }, \
   .p = { -1, -1 }, \
+  .logv = TIPIDEE_LOG_DEFAULT, \
   .maxrqbody = 0, \
   .maxcgibody = 0, \
   .defaultport = 0, \
   .indexn = 0, \
-  .verbosity = 1, \
   .cont = 1, \
   .ssl = 0 \
 }
@@ -92,27 +71,43 @@ extern void tipideed_harden (unsigned int) ;
 
  /* Responses */
 
-extern void response_error (tipidee_rql const *, char const *, char const *, int) ;
-extern void response_error_and_exit (tipidee_rql const *, char const *, char const *) gccattr_noreturn ;
-extern void response_error_and_die (tipidee_rql const *, int e, char const *, char const *, char const *const *, unsigned int, int) gccattr_noreturn ;
-
-#define exit_400(r, s) response_error_and_exit(r, "400 Bad Request", s)
-extern void exit_405 (tipidee_rql const *, uint32_t) gccattr_noreturn ;
-#define exit_408(r) response_error_and_exit(r, "408 Request Timeout", "")
-#define exit_413(r, s) response_error_and_exit(r, "413 Request Entity Too Large", s)
-#define exit_501(r, s) response_error_and_exit(r, "501 Not Implemented", s)
-
-#define respond_403(r) response_error(r, "403 Forbidden", "Missing credentials to access the URI.", 0)
-#define respond_404(r) response_error(r, "404 Not Found", "The request URI was not found.", 0)
-#define respond_414(r) response_error(r, "414 URI Too Long", "The request URI had an oversized component.", 0)
+extern void response_error (tipidee_rql const *, unsigned int, char const *, char const *, uint32_t) ;  /* set bit 0 for Connection: close, bit 1 for preexit */
+extern void response_error_and_exit (tipidee_rql const *, unsigned int, char const *, char const *, uint32_t) gccattr_noreturn ;
+extern void response_error_and_die (tipidee_rql const *, int e, unsigned int, char const *, char const *, char const *const *, unsigned int, uint32_t) gccattr_noreturn ;
+
+ /*
+    preexit is meant to be called before tipidee_log_request(), it won't log an answer line.
+    Use for early parsing, when the request isn't even validated yet.
+    exit is meant to be called after tipidee_log_request(), it will log an answer line.
+    respond can only happen after tipidee_log_request(), it will log an answer line.
+
+    exit will log an informational exit line.
+    die will not; there will be a fatal line instead.
+    die will log an answer line. There is no "predie", we just use strerr_die instead.
+ */
+
+#define preexit_400(r, s) response_error_and_exit(r, 400, "Bad Request", s, 2)
+#define exit_400(r, s) response_error_and_exit(r, 400, "Bad Request", s, 0)
+extern void exit_405 (tipidee_rql const *, uint32_t) gccattr_noreturn ;  /* set bit 0 for Allow: POST, bit 1 for preexit */
+#define preexit_408(r) response_error_and_exit(r, 408, "Request Timeout", "", 2)
+#define exit_408(r) response_error_and_exit(r, 408, "Request Timeout", "", 0)
+#define preexit_413(r, s) response_error_and_exit(r, 413, "Request Entity Too Large", s, 2)
+#define exit_413(r, s) response_error_and_exit(r, 413, "Request Entity Too Large", s, 0)
+#define preexit_501(r, s) response_error_and_exit(r, 501, "Not Implemented", s, 2)
+#define exit_501(r, s) response_error_and_exit(r, 501, "Not Implemented", s, 0)
+
+#define respond_403(r) response_error(r, 403, "Forbidden", "Missing credentials to access the URI.", 0)
+#define respond_404(r) response_error(r, 404, "Not Found", "The request URI was not found.", 0)
+#define respond_414(r) response_error(r, 414, "URI Too Long", "The request URI had an oversized component.", 0)
 extern void respond_30x (tipidee_rql const *, tipidee_redirection const *) ;
-#define respond_504(r) response_error(r, "504 Gateway Timeout", "The CGI script took too long to answer.", 0)
+#define respond_504(r) response_error(r, 504, "Gateway Timeout", "The CGI script took too long to answer.", 0)
+
+#define diefx(r, e, status, rsl, text, ...) response_error_and_die(r, e, status, rsl, text, strerr_array(PROG, ": fatal: ", __VA_ARGS__), sizeof(strerr_array(__VA_ARGS__))/sizeof(char const *)+2, 0)
+#define diefusys(r, e, status, rsl, text, ...) response_error_and_die(r, e, status, rsl, text, strerr_array(PROG, ": fatal: ", "unable to ", __VA_ARGS__), sizeof(strerr_array(__VA_ARGS__))/sizeof(char const *)+3, 1)
+#define die500x(r, e, ...) diefx(r, e, 500, "Internal Server Error", "Bad server configuration.", __VA_ARGS__)
+#define die500sys(r, e, ...) diefusys(r, e, 500, "Internal Server Error", "System error.", __VA_ARGS__)
+#define die502x(r, e, ...) diefx(r, e, 502, "Bad Gateway", "Bad CGI script.", __VA_ARGS__)
 
-#define diefx(r, e, rsl, text, ...) response_error_and_die(r, e, rsl, text, strerr_array(PROG, ": fatal: ", __VA_ARGS__), sizeof(strerr_array(__VA_ARGS__))/sizeof(char const *)+2, 0)
-#define diefusys(r, e, rsl, text, ...) response_error_and_die(r, e, rsl, text, strerr_array(PROG, ": fatal: ", "unable to ", __VA_ARGS__), sizeof(strerr_array(__VA_ARGS__))/sizeof(char const *)+3, 1)
-#define die500x(r, e, ...) diefx(r, e, "500 Internal Server Error", "Bad server configuration.", __VA_ARGS__)
-#define die500sys(r, e, ...) diefusys(r, e, "500 Internal Server Error", "System error.", __VA_ARGS__)
-#define die502x(r, e, ...) diefx(r, e, "502 Bad Gateway", "Bad CGI script.", __VA_ARGS__)
 
  /* Trace */
 
@@ -140,15 +135,4 @@ extern int respond_304 (tipidee_rql const *, char const *, struct stat const *)
 
 extern int respond_cgi (tipidee_rql *, char const *, size_t, char const *, char *, tipidee_headers const *, tipidee_resattr const *, char const *, size_t) ;
 
-
- /* log */
-
-extern void log_start (void) ;
-extern void log_and_exit (int) gccattr_noreturn ;
-extern void log_request (tipidee_rql const *) ;
-extern void log_regular (char const *, char const *, int, char const *) ;
-extern void log_response (char const *, char const *) ;
-extern void log_nph (char const *const *, char const *const *) ;
-extern void log_cgi (char const *const *, char const *const *) ;
-
 #endif
diff --git a/src/tipideed/tipideed.c b/src/tipideed/tipideed.c
index b85f509..fb5ede4 100644
--- a/src/tipideed/tipideed.c
+++ b/src/tipideed/tipideed.c
@@ -30,7 +30,7 @@
 #include <tipidee/tipidee.h>
 #include "tipideed-internal.h"
 
-#define USAGE "tipideed [ -v verbosity ] [ -f cdbfile ] [ -d basedir ] [ -R ] [ -U ]"
+#define USAGE "tipideed [ -f cdbfile ] [ -d basedir ] [ -R ] [ -U ]"
 #define dieusage() strerr_dieusage(100, USAGE)
 #define dienomem() strerr_diefu1sys(111, "stralloc_catb")
 
@@ -45,7 +45,13 @@ static void sigchld_handler (int sig)
   wait_reap() ;
 }
 
-static inline void prep_env (void)
+static inline void log_and_exit (int e)
+{
+  tipidee_log_exit(g.logv, e) ;
+  _exit(e) ;
+}
+
+static inline void prep_env (size_t *remoteip, size_t *remotehost)
 {
   static char const basevars[] = "PROTO\0TCPCONNNUM\0GATEWAY_INTERFACE=CGI/1.1\0SERVER_SOFTWARE=tipidee/" TIPIDEE_VERSION ;
   static char const sslvars[] = "SSL_PROTOCOL\0SSL_CIPHER\0SSL_TLS_SNI_SERVERNAME\0SSL_PEER_CERT_HASH\0SSL_PEER_CERT_SUBJECT\0HTTPS=on" ;
@@ -77,7 +83,6 @@ static inline void prep_env (void)
     if (!uint160_scan(x, &g.defaultport)) strerr_dieinvalid(100, var) ;
     if (!stralloc_catb(&g.sa, var, protolen + 10)
      || !stralloc_catb(&g.sa, "SERVER_PORT=", 12)) dienomem() ;
-    g.localport = g.sa.len ;
     m = uint16_fmt(fmt, g.defaultport) ; fmt[m++] = 0 ;
     if (!stralloc_catb(&g.sa, fmt, m)) dienomem() ;
 
@@ -87,7 +92,6 @@ static inline void prep_env (void)
     if (!ip46_scan(x, &ip)) strerr_dieinvalid(100, var) ;
     if (!stralloc_catb(&g.sa, var, protolen + 8)
      || !stralloc_catb(&g.sa, "SERVER_ADDR=", 12)) dienomem() ;
-    g.localip = g.sa.len ;
     m = ip46_fmt(fmt, &ip) ; fmt[m++] = 0 ;
     if (!stralloc_catb(&g.sa, fmt, m)) dienomem() ;
 
@@ -105,7 +109,6 @@ static inline void prep_env (void)
     if (!uint160_scan(x, &port)) strerr_dieinvalid(100, var) ;
     if (!stralloc_catb(&g.sa, var, protolen + 11)
      || !stralloc_catb(&g.sa, "REMOTE_PORT=", 12)) dienomem() ;
-    g.remoteport = g.sa.len ;
     m = uint16_fmt(fmt, port) ; fmt[m++] = 0 ;
     if (!stralloc_catb(&g.sa, fmt, m)) dienomem() ;
 
@@ -115,7 +118,7 @@ static inline void prep_env (void)
     if (!ip46_scan(x, &ip)) strerr_dieinvalid(100, var) ;
     if (!stralloc_catb(&g.sa, var, protolen + 9)
      || !stralloc_catb(&g.sa, "REMOTE_ADDR=", 12)) dienomem() ;
-    g.remoteip = g.sa.len ;
+    *remoteip = g.sa.len ;
     m = ip46_fmt(fmt, &ip) ; fmt[m++] = 0 ;
     if (!stralloc_catb(&g.sa, fmt, m)) dienomem() ;
 
@@ -123,7 +126,7 @@ static inline void prep_env (void)
     x = getenv(var) ;
     if ((x && !stralloc_catb(&g.sa, var, protolen + 11))
      || !stralloc_catb(&g.sa, "REMOTE_HOST=", 12)) dienomem() ;
-    g.remotehost = g.sa.len ;
+    *remotehost = g.sa.len ;
     if (x)
     {
       if (!stralloc_cats(&g.sa, x)) dienomem() ;
@@ -132,7 +135,7 @@ static inline void prep_env (void)
     {
       if (!stralloc_readyplus(&g.sa, m + 2)) dienomem() ;
       if (ip46_is6(&ip)) stralloc_catb(&g.sa, "[", 1) ;
-      stralloc_catb(&g.sa, g.sa.s + g.remoteip, m) ;
+      stralloc_catb(&g.sa, g.sa.s + *remoteip, m) ;
       if (ip46_is6(&ip)) stralloc_catb(&g.sa, "]", 1) ;
     }
     if (!stralloc_0(&g.sa)) dienomem() ;
@@ -326,8 +329,11 @@ static inline int serve (tipidee_rql *rql, char const *docroot, char *uribuf, ti
   }
 
   if (rql->m == TIPIDEE_METHOD_OPTIONS)
-    return respond_options(rql, ra.iscgi) ;
-  else if (ra.iscgi)
+    return respond_options(rql, 2 | ra.iscgi) ;
+
+  tipidee_log_resource(g.logv, rql, docroot, fn, &ra) ;
+
+  if (ra.iscgi)
     return respond_cgi(rql, fn, docrootlen, infopath, uribuf, hdr, &ra, body, bodylen) ;
 
   infopath = tipidee_headers_search(hdr, "If-Modified-Since") ;
@@ -353,24 +359,14 @@ int main (int argc, char const *const *argv, char const *const *envp)
     char const *conffile = TIPIDEE_SYSCONFPREFIX "tipidee.conf.cdb" ;
     char const *newroot = 0 ;
     unsigned int h = 0 ;
-    int gotv = 0 ;
     subgetopt l = SUBGETOPT_ZERO ;
 
     for (;;)
     {
-      int opt = subgetopt_r(argc, argv, "v:f:d:RU", &l) ;
+      int opt = subgetopt_r(argc, argv, "f:d:RU", &l) ;
       if (opt == -1) break ;
       switch (opt)
       {
-        case 'v' :
-        {
-          unsigned int n ;
-          if (!uint0_scan(l.arg, &n)) dieusage() ;
-          if (n > 7) n = 7 ;
-          g.verbosity = n ;
-          gotv = 1 ;
-          break ;
-        }
         case 'f' : conffile = l.arg ; break ;
         case 'd' : newroot = l.arg ; break ;
         case 'R' : h |= 3 ; break ;
@@ -386,30 +382,31 @@ int main (int argc, char const *const *argv, char const *const *envp)
     if (newroot && chdir(newroot) == -1)
       strerr_diefu2sys(111, "chdir to ", newroot) ;
     tipideed_harden(h) ;
-    if (!gotv) g.verbosity = get_uint32("G:verbosity") ;
   }
 
-  prep_env() ;
-  inittto(&g.readtto, "G:read_timeout") ;
-  inittto(&g.writetto, "G:write_timeout") ;
-  inittto(&g.cgitto, "G:cgi_timeout") ;
-  g.maxrqbody = get_uint32("G:max_request_body_length") ;
-  g.maxcgibody = get_uint32("G:max_cgi_body_length") ;
   {
-    unsigned int n = tipidee_conf_get_argv(&g.conf, "G:index_file", g.indexnames, 16, &g.indexlen) ;
+    size_t remoteip, remotehost ;
+    unsigned int n ;
+    prep_env(&remoteip, &remotehost) ;
+    inittto(&g.readtto, "G:read_timeout") ;
+    inittto(&g.writetto, "G:write_timeout") ;
+    inittto(&g.cgitto, "G:cgi_timeout") ;
+    g.maxrqbody = get_uint32("G:max_request_body_length") ;
+    g.maxcgibody = get_uint32("G:max_cgi_body_length") ;
+    g.logv = get_uint32("G:logv") ;
+    n = tipidee_conf_get_argv(&g.conf, "G:index_file", g.indexnames, 16, &g.indexlen) ;
     if (!n) strerr_dief3x(102, "bad", " config value for ", "G:index_file") ;
     g.indexn = n-1 ;
-  }
-
-  if (ndelay_on(0) == -1 || ndelay_on(1) == -1)
-    strerr_diefu1sys(111, "set I/O nonblocking") ;
-  init_splice_pipe() ;
-  if (!sig_catch(SIGCHLD, &sigchld_handler))
-    strerr_diefu1sys(111, "set SIGCHLD handler") ;
-  if (!tain_now_set_stopwatch_g())
-    strerr_diefu1sys(111, "initialize clock") ;
 
-  log_start() ;
+    if (ndelay_on(0) == -1 || ndelay_on(1) == -1)
+      strerr_diefu1sys(111, "set I/O nonblocking") ;
+    init_splice_pipe() ;
+    if (!sig_catch(SIGCHLD, &sigchld_handler))
+      strerr_diefu1sys(111, "set SIGCHLD handler") ;
+    if (!tain_now_set_stopwatch_g())
+      strerr_diefu1sys(111, "initialize clock") ;
+    tipidee_log_start(g.logv, g.sa.s + remoteip, g.sa.s + remotehost) ;
+  }
 
 
  /* Main loop */
@@ -436,11 +433,11 @@ int main (int argc, char const *const *argv, char const *const *envp)
       case -1 : log_and_exit(1) ;  /* Malicious or shitty client */
       case 0 : break ;
       case 99 : g.cont = 0 ; continue ;  /* timeout, it's ok */
-      case 400 : exit_400(&rql, "Syntax error in request line") ;
+      case 400 : preexit_400(&rql, "Syntax error in request line") ;
       default : strerr_dief2x(101, "can't happen: ", "unknown tipidee_rql_read return code") ;
     }
     if (rql.http_major != 1) log_and_exit(1) ;
-    if (rql.http_minor > 1) exit_400(&rql, "Bad HTTP version") ;
+    if (rql.http_minor > 1) preexit_400(&rql, "Bad HTTP version") ;
 
     content_length = 0 ;
     tipidee_headers_init(&hdr, hdrbuf, HDR_BUFSIZE) ;
@@ -449,11 +446,11 @@ int main (int argc, char const *const *argv, char const *const *envp)
     {
       case -1 : log_and_exit(1) ;  /* connection issue, client timeout, etc. */
       case 0 : break ;
-      case 400 : exit_400(&rql, "Syntax error in headers") ;
-      case 408 : exit_408(&rql) ;  /* timeout */
-      case 413 : exit_413(&rql, hdr.n >= TIPIDEE_HEADERS_MAX ? "Too many headers" : "Too much header data") ;
-      case 500 : die500x(&rql, 101, "can't happen: ", "avltreen_insert failed") ;
-      default : die500x(&rql, 101, "can't happen: ", "unknown tipidee_headers_parse return code") ;
+      case 400 : preexit_400(&rql, "Syntax error in headers") ;
+      case 408 : preexit_408(&rql) ;  /* timeout */
+      case 413 : preexit_413(&rql, hdr.n >= TIPIDEE_HEADERS_MAX ? "Too many headers" : "Too much header data") ;
+      case 500 : strerr_dief2x(101, "can't happen: ", "avltreen_insert failed") ;
+      default : strerr_dief2x(101, "can't happen: ", "unknown tipidee_headers_parse return code") ;
     }
 
     if (!rql.http_minor) g.cont = 0 ;
@@ -470,7 +467,7 @@ int main (int argc, char const *const *argv, char const *const *envp)
     x = tipidee_headers_search(&hdr, "Transfer-Encoding") ;
     if (x)
     {
-      if (strcasecmp(x, "chunked")) exit_400(&rql, "unsupported Transfer-Encoding") ;
+      if (strcasecmp(x, "chunked")) preexit_400(&rql, "unsupported Transfer-Encoding") ;
       else tcoding = TIPIDEE_TRANSFERCODING_CHUNKED ;
     }
     else
@@ -478,7 +475,7 @@ int main (int argc, char const *const *argv, char const *const *envp)
       x = tipidee_headers_search(&hdr, "Content-Length") ;
       if (x)
       {
-        if (!size_scan(x, &content_length)) exit_400(&rql, "Invalid Content-Length") ;
+        if (!size_scan(x, &content_length)) preexit_400(&rql, "Invalid Content-Length") ;
         else if (content_length) tcoding = TIPIDEE_TRANSFERCODING_FIXED ;
         else tcoding = TIPIDEE_TRANSFERCODING_NONE ;
       }
@@ -486,22 +483,22 @@ int main (int argc, char const *const *argv, char const *const *envp)
     }
 
     if (tcoding != TIPIDEE_TRANSFERCODING_NONE && rql.m != TIPIDEE_METHOD_POST)
-      exit_400(&rql, "only POST requests can have an entity body") ;
+      preexit_400(&rql, "only POST requests can have an entity body") ;
 
     switch (rql.m)
     {
       case TIPIDEE_METHOD_GET :
       case TIPIDEE_METHOD_HEAD :
-      case TIPIDEE_METHOD_POST : break ;
+      case TIPIDEE_METHOD_POST :
+      case TIPIDEE_METHOD_TRACE : break ;
       case TIPIDEE_METHOD_OPTIONS :
         if (!rql.uri.path) { respond_options(&rql, 1) ; continue ; }
         break ;
       case TIPIDEE_METHOD_PUT :
-      case TIPIDEE_METHOD_DELETE : exit_405(&rql, 1) ;
-      case TIPIDEE_METHOD_TRACE : respond_trace(hdrbuf, &rql, &hdr) ; continue ;
-      case TIPIDEE_METHOD_CONNECT : exit_501(&rql, "CONNECT method unsupported") ;
-      case TIPIDEE_METHOD_PRI : exit_501(&rql, "PRI method attempted with HTTP version 1") ;
-      default : die500x(&rql, 101, "can't happen: unknown HTTP method") ;
+      case TIPIDEE_METHOD_DELETE : exit_405(&rql, 3) ;
+      case TIPIDEE_METHOD_CONNECT : preexit_501(&rql, "CONNECT method unsupported") ;
+      case TIPIDEE_METHOD_PRI : preexit_501(&rql, "PRI method attempted with HTTP version 1") ;
+      default : strerr_dief2x(101, "can't happen: ", "unknown HTTP method") ;
     }
 
     if (rql.http_minor)
@@ -512,16 +509,23 @@ int main (int argc, char const *const *argv, char const *const *envp)
         char *p = strchr(x, ':') ;
         if (p)
         {
-          if (!uint160_scan(p+1, &rql.uri.port)) exit_400(&rql, "Invalid Host header") ;
+          if (!uint160_scan(p+1, &rql.uri.port)) preexit_400(&rql, "Invalid Host header") ;
           *p = 0 ;
         }
-        if (!*x || *x == '.') exit_400(&rql, "Invalid Host header") ;
+        if (!*x || *x == '.') preexit_400(&rql, "Invalid Host header") ;
         rql.uri.host = x ;
       }
-      else if (!rql.uri.host) exit_400(&rql, "Missing Host header") ;
+      else if (!rql.uri.host) preexit_400(&rql, "Missing Host header") ;
     }
     else if (!rql.uri.host) rql.uri.host = g.defaulthost ;
     if (!rql.uri.port) rql.uri.port = g.defaultport ;
+    tipidee_log_request(g.logv, &rql, &hdr, &g.sa) ;
+
+    if (rql.m == TIPIDEE_METHOD_TRACE)
+    {
+      respond_trace(hdrbuf, &rql, &hdr) ;
+      continue ;
+    }
 
     {
       size_t hostlen = strlen(rql.uri.host) ;
@@ -560,10 +564,8 @@ int main (int argc, char const *const *argv, char const *const *envp)
         default : break ;
       }
 
-      log_request(&rql) ;
-
 
-     /* And serve the resource. The loop is in case of CGI local-redirection. */
+     /* Find and serve the resource. The loop is in case of CGI local-redirection. */
 
       while (serve(&rql, docroot, uribuf, &hdr, bodysa.s, bodysa.len))
         if (localredirs++ >= MAX_LOCALREDIRS)
diff --git a/src/tipideed/trace.c b/src/tipideed/trace.c
index 4761ea5..122d269 100644
--- a/src/tipideed/trace.c
+++ b/src/tipideed/trace.c
@@ -10,6 +10,7 @@
 
 #include <tipidee/method.h>
 #include <tipidee/response.h>
+#include <tipidee/log.h>
 #include "tipideed-internal.h"
 
 int respond_trace (char const *buf, tipidee_rql const *rql, tipidee_headers const *hdr)
@@ -17,7 +18,7 @@ int respond_trace (char const *buf, tipidee_rql const *rql, tipidee_headers cons
   tain deadline ;
   size_t cl = 0 ;
   char fmt[SIZE_FMT] ;
-  tipidee_response_status_line(buffer_1, rql, "200 OK") ;
+  tipidee_response_status(buffer_1, rql, 200, "OK") ;
   tipidee_response_header_common_put_g(buffer_1, 0) ;
   buffer_putsnoflush(buffer_1, "Content-Type: message/http\r\nContent-Length: ") ;
   cl += strlen(tipidee_method_tostr(rql->m)) + 1;
@@ -48,6 +49,7 @@ int respond_trace (char const *buf, tipidee_rql const *rql, tipidee_headers cons
   buffer_putnoflush(buffer_1, ".", 1) ;
   buffer_putnoflush(buffer_1, fmt, uint_fmt(fmt, rql->http_minor)) ;
   buffer_putsnoflush(buffer_1, "\r\n") ;
+  tipidee_log_answer(g.logv, rql, 200, cl) ;
   for (size_t i = 0 ; i < hdr->n ; i++)
   {
     size_t len = strlen(buf + hdr->list[i].left) ;