lws access log option and lwsws conf

This adds the ability to store apache-compatible logs to a file given at
vhost-creation time.

lwsws conf can set it per-vhost using "access-log": "<filepath>"

The feature defaults to disabled at cmake, it can be set independently but
LWS_WITH_LWSWS set it on.

Signed-off-by: Andy Green <andy@warmcat.com>

CMakeLists.txt

@@ -94,11 +94,14 @@ option(LWS_WITH_CGI "Include CGI (spawn process with network-connected stdin/out
 option(LWS_WITH_HTTP_PROXY "Support for rewriting HTTP proxying" OFF)
 option(LWS_WITH_LWSWS "Libwebsockets Webserver" OFF)
 option(LWS_WITH_PLUGINS "Support plugins for protocols and extensions" OFF)
+option(LWS_WITH_ACCESS_LOG "Support generating Apache-compatible access logs" OFF)
+
 
 if (LWS_WITH_LWSWS)
  message(STATUS "LWS_WITH_LWSWS --> Enabling LWS_WITH_PLUGINS and LWS_WITH_LIBUV")
  set(LWS_WITH_PLUGINS 1)
  set(LWS_WITH_LIBUV 1)
+ set(LWS_WITH_ACCESS_LOG 1)
 endif()
 
 if (LWS_WITH_PLUGINS AND NOT LWS_WITH_LIBUV)
@@ -1462,6 +1465,7 @@ message(" LWS_HAVE_SSL_CTX_set1_param = ${LWS_HAVE_SSL_CTX_set1_param}")
 message(" LWS_WITH_HTTP_PROXY = ${LWS_WITH_HTTP_PROXY}")
 message(" LIBHUBBUB_LIBRARIES = ${LIBHUBBUB_LIBRARIES}")
 message(" PLUGINS = ${PLUGINS_LIST}")
+message(" LWS_WITH_ACCESS_LOG = ${LWS_WITH_ACCESS_LOG}")
 message("---------------------------------------------------------------------")
 
 # These will be available to parent projects including libwebsockets using add_subdirectory()

README.lwsws.md

@@ -167,6 +167,7 @@ Other vhost options
 
  - "`sts`": "1" causes lwsws to send a Strict Transport Security header with responses that informs the client he should never accept to connect to this address using http.  This is needed to get the A+ security rating from SSL Labs for your server.
 
+ - "`access-log`": "filepath"   sets where apache-compatible access logs will be written
 
 Mounts
 ------

lib/context.c

@@ -353,6 +353,23 @@ lws_create_vhost(struct lws_context *context,
 	if (vh->options & LWS_SERVER_OPTION_STS)
 		lwsl_notice("   STS enabled\n");
 
+#ifdef LWS_WITH_ACCESS_LOG
+	if (info->log_filepath) {
+		vh->log_fd = open(info->log_filepath, O_CREAT | O_APPEND | O_RDWR, 0600);
+		if (vh->log_fd == LWS_INVALID_FILE) {
+			lwsl_err("unable to open log filepath %s\n",
+				 info->log_filepath);
+			goto bail;
+		}
+		if (context->uid != -1)
+			if (chown(info->log_filepath, context->uid,
+				  context->gid) == -1)
+				lwsl_err("unable to chown log file %s\n",
+						info->log_filepath);
+	} else
+		vh->log_fd = LWS_INVALID_FILE;
+#endif
+
 	if (lws_context_init_server_ssl(info, vh))
 		goto bail;
 
@@ -779,6 +796,11 @@ lws_context_destroy(struct lws_context *context)
 			lws_free((void *)vh->extensions);
 #endif
 #endif
+#ifdef LWS_WITH_ACCESS_LOG
+		if (vh->log_fd != LWS_INVALID_FILE)
+			close(vh->log_fd);
+#endif
+
 		vh1 = vh->vhost_next;
 		lws_free(vh);
 		vh = vh1;

lib/header.c

@@ -147,6 +147,13 @@ lws_add_http_header_status(struct lws *wsi, unsigned int code,
 	unsigned char code_and_desc[60];
 	const char *description = "";
 	int n;
+	static const char * const hver[] = {
+		"http/1.0", "http/1.1", "http/2"
+	};
+
+#ifdef LWS_WITH_ACCESS_LOG
+	wsi->access_log.response = code;
+#endif
 
 #ifdef LWS_USE_HTTP2
 	if (wsi->mode == LWSCM_HTTP2_SERVING)
@@ -157,7 +164,8 @@ lws_add_http_header_status(struct lws *wsi, unsigned int code,
 	if (code >= 500 && code < (500 + ARRAY_SIZE(err500)))
 		description = err500[code - 500];
 
-	n = sprintf((char *)code_and_desc, "HTTP/1.0 %u %s", code, description);
+	n = sprintf((char *)code_and_desc, "%s %u %s",
+		    hver[wsi->u.http.request_version], code, description);
 
 	return lws_add_http_header_by_name(wsi, NULL, code_and_desc,
 					   n, p, end);

lib/libwebsockets.c

@@ -151,6 +151,8 @@ lws_close_free_wsi(struct lws *wsi, enum lws_close_status reason)
 	if (!wsi)
 		return;
 
+	lws_access_log(wsi);
+
 	context = wsi->context;
 	pt = &context->pt[(int)wsi->tsi];
 
@@ -641,6 +643,44 @@ lws_get_addresses(struct lws_context *context, void *ads, char *name,
 #endif
 }
 
+const char *
+lws_get_peer_simple(struct lws *wsi, char *name, int namelen)
+{
+#if LWS_POSIX
+	socklen_t len, olen;
+#ifdef LWS_USE_IPV6
+	struct sockaddr_in6 sin6;
+#endif
+	struct sockaddr_in sin4;
+	int af = AF_INET;
+	void *p, *q;
+
+#ifdef LWS_USE_IPV6
+	if (LWS_IPV6_ENABLED(wsi->context)) {
+		len = sizeof(sin6);
+		p = &sin6;
+		af = AF_INET6;
+		q = &sin6.sin6_addr;
+	} else
+#endif
+	{
+		len = sizeof(sin4);
+		p = &sin4;
+		q = &sin4.sin_addr;
+	}
+
+	olen = len;
+	if (getpeername(wsi->sock, p, &len) < 0 || len > olen) {
+		lwsl_warn("getpeername: %s\n", strerror(LWS_ERRNO));
+		return NULL;
+	}
+
+	return inet_ntop(af, q, name, namelen);
+#else
+	return NULL;
+#endif
+}
+
 /**
  * lws_get_peer_addresses() - Get client address information
  * @wsi:	Local struct lws associated with
@@ -2161,6 +2201,38 @@ lws_set_extension_option(struct lws *wsi, const char *ext_name,
 }
 #endif
 
+#ifdef LWS_WITH_ACCESS_LOG
+int
+lws_access_log(struct lws *wsi)
+{
+	char *p = wsi->access_log.user_agent, ass[512];
+	int l;
+
+	if (!wsi->access_log_pending)
+		return 0;
+
+	if (!p)
+		p = "";
+
+	l = snprintf(ass, sizeof(ass) - 1, "%s %d %lu %s\n",
+		     wsi->access_log.header_log,
+		     wsi->access_log.response, wsi->access_log.sent, p);
+
+	if (wsi->vhost->log_fd != LWS_INVALID_FILE) {
+		if (write(wsi->vhost->log_fd, ass, l) != l)
+			lwsl_err("Failed to write log\n");
+	} else
+		lwsl_err("%s", ass);
+
+	if (wsi->access_log.header_log)
+		lws_free(wsi->access_log.header_log);
+	if (wsi->access_log.user_agent)
+		lws_free(wsi->access_log.user_agent);
+	wsi->access_log_pending = 0;
+
+	return 0;
+}
+#endif
 
 LWS_EXTERN int
 lws_json_dump_vhost(const struct lws_vhost *vh, char *buf, int len)

lib/libwebsockets.h

@@ -1476,6 +1476,7 @@ struct lws_context_creation_info {
 	const char *plugins_dir;			/* context */
 	struct lws_protocol_vhost_options *pvo;		/* VH */
 	int keepalive_timeout;				/* VH */
+	const char *log_filepath;			/* VH */
 
 	/* Add new things just above here ---^
 	 * This is part of the ABI, don't needlessly break compatibility

lib/output.c

@@ -248,6 +248,10 @@ LWS_VISIBLE int lws_write(struct lws *wsi, unsigned char *buf, size_t len,
 	int pre = 0, n;
 	size_t orig_len = len;
 
+#ifdef LWS_WITH_ACCESS_LOG
+	wsi->access_log.sent += len;
+#endif
+
 	if (wsi->state == LWSS_ESTABLISHED && wsi->u.ws.tx_draining_ext) {
 		/* remove us from the list */
 		struct lws **w = &pt->tx_draining_ext_list;

lib/private-libwebsockets.h

@@ -677,6 +677,9 @@ struct lws_vhost {
 	int ka_probes;
 	int ka_interval;
 	int keepalive_timeout;
+#ifdef LWS_WITH_ACCESS_LOG
+	int log_fd;
+#endif
 
 #ifdef LWS_OPENSSL_SUPPORT
 	int use_ssl;
@@ -1155,6 +1158,15 @@ enum lws_chunk_parser {
 
 struct lws_rewrite;
 
+#ifdef LWS_WITH_ACCESS_LOG
+struct lws_access_log {
+	char *header_log;
+	char *user_agent;
+	unsigned long sent;
+	int response;
+};
+#endif
+
 struct lws {
 
 	/* structs */
@@ -1192,6 +1204,9 @@ struct lws {
 	const struct lws_protocols *protocol;
 	struct lws *timeout_list;
 	struct lws **timeout_list_prev;
+#ifdef LWS_WITH_ACCESS_LOG
+	struct lws_access_log access_log;
+#endif
 	void *user_space;
 	/* rxflow handling */
 	unsigned char *rxflow_buffer;
@@ -1236,6 +1251,9 @@ struct lws {
 	unsigned int socket_is_permanently_unusable:1;
 	unsigned int rxflow_change_to:2;
 	unsigned int more_rx_waiting:1; /* has to live here since ah may stick to end */
+#ifdef LWS_WITH_ACCESS_LOG
+	unsigned int access_log_pending:1;
+#endif
 #ifndef LWS_NO_CLIENT
 	unsigned int do_ws:1; /* whether we are doing http or ws flow */
 	unsigned int chunked:1; /* if the clientside connection is chunked */
@@ -1686,6 +1704,16 @@ LWS_EXTERN int
 lws_get_addresses(struct lws_context *context, void *ads, char *name,
 		  int name_len, char *rip, int rip_len);
 
+LWS_EXTERN const char *
+lws_get_peer_simple(struct lws *wsi, char *name, int namelen);
+
+#ifdef LWS_WITH_ACCESS_LOG
+LWS_EXTERN int
+lws_access_log(struct lws *wsi);
+#else
+#define lws_access_log(_a)
+#endif
+
 LWS_EXTERN int
 lws_cgi_kill_terminated(struct lws_context_per_thread *pt);
 

lib/server.c

@@ -299,6 +299,7 @@ lws_http_action(struct lws *wsi)
 	int http_version_len;
 	char *uri_ptr = NULL;
 	int uri_len = 0, best = 0;
+	int meth = -1;
 
 	static const unsigned char methods[] = {
 		WSI_TOKEN_GET_URI,
@@ -311,7 +312,7 @@ lws_http_action(struct lws *wsi)
 		WSI_TOKEN_HTTP_COLON_PATH,
 #endif
 	};
-#ifdef _DEBUG
+#if defined(_DEBUG) || defined(LWS_WITH_ACCESS_LOG)
 	static const char * const method_names[] = {
 		"GET", "POST", "OPTIONS", "PUT", "PATCH", "DELETE",
 #ifdef LWS_USE_HTTP2
@@ -344,9 +345,12 @@ lws_http_action(struct lws *wsi)
 			uri_len = lws_hdr_total_length(wsi, methods[n]);
 			lwsl_info("Method: %s request for '%s'\n",
 				  	method_names[n], uri_ptr);
+			meth = n;
 			break;
 		}
 
+	(void)meth;
+
 	/* we insist on absolute paths */
 
 	if (uri_ptr[0] != '/') {
@@ -450,6 +454,66 @@ lws_http_action(struct lws *wsi)
 #endif
 #endif
 
+#ifdef LWS_WITH_ACCESS_LOG
+	/*
+	 * Produce Apache-compatible log string for wsi, like this:
+	 *
+	 * 2.31.234.19 - - [27/Mar/2016:03:22:44 +0800]
+	 * "GET /aep-screen.png HTTP/1.1"
+	 * 200 152987 "https://libwebsockets.org/index.html"
+	 * "Mozilla/5.0 (Macint... Chrome/49.0.2623.87 Safari/537.36"
+	 *
+	 */
+	{
+		static const char * const hver[] = {
+			"http/1.0", "http/1.1", "http/2"
+		};
+#ifdef LWS_USE_IPV6
+		char ads[INET6_ADDRSTRLEN];
+#else
+		char ads[INET_ADDRSTRLEN];
+#endif
+		char da[64];
+		const char *pa, *me;
+		struct tm *tmp;
+		time_t t = time(NULL);
+		int l = 256;
+
+		if (wsi->access_log_pending)
+			lws_access_log(wsi);
+
+		wsi->access_log.header_log = lws_malloc(l);
+
+		tmp = localtime(&t);
+		if (tmp)
+			strftime(da, sizeof(da), "%d/%b/%Y:%H:%M:%S %z", tmp);
+		else
+			strcpy(da, "01/Jan/1970:00:00:00 +0000");
+
+		pa = lws_get_peer_simple(wsi, ads, sizeof(ads));
+		if (!pa)
+			pa = "(unknown)";
+
+		if (meth >= 0)
+			me = method_names[meth];
+		else
+			me = "unknown";
+
+		snprintf(wsi->access_log.header_log, l,
+			 "%s - - [%s] \"%s %s %s\"",
+			 pa, da, me, uri_ptr,
+			 hver[wsi->u.http.request_version]);
+
+		l = lws_hdr_total_length(wsi, WSI_TOKEN_HTTP_USER_AGENT);
+		if (l) {
+			wsi->access_log.user_agent = lws_malloc(l + 2);
+			lws_hdr_copy(wsi, wsi->access_log.user_agent,
+				     l + 1, WSI_TOKEN_HTTP_USER_AGENT);
+		}
+		wsi->access_log_pending = 1;
+	}
+#endif
+
 	/* can we serve it from the mount list? */
 
 	hm = wsi->vhost->mount_list;
@@ -1019,6 +1083,8 @@ lws_http_transaction_completed(struct lws *wsi)
 {
 	int n = NO_PENDING_TIMEOUT;
 
+	lws_access_log(wsi);
+
 	lwsl_debug("%s: wsi %p\n", __func__, wsi);
 	/* if we can't go back to accept new headers, drop the connection */
 	if (wsi->u.http.connection_type != HTTP_CONNECTION_KEEP_ALIVE) {

lws_config.h.in

@@ -92,6 +92,9 @@
 /* HTTP Proxy support */
 #cmakedefine LWS_WITH_HTTP_PROXY
 
+/* Http access log support */
+#cmakedefine LWS_WITH_ACCESS_LOG
+
 /* Maximum supported service threads */
 #define LWS_MAX_SMP ${LWS_MAX_SMP}
 

lwsws/conf.c

@@ -46,6 +46,7 @@ static const char * const paths_vhosts[] = {
 	"vhosts[].host-ssl-key",
 	"vhosts[].host-ssl-cert",
 	"vhosts[].host-ssl-ca",
+	"vhosts[].access-log",
 	"vhosts[].mounts[].mountpoint",
 	"vhosts[].mounts[].origin",
 	"vhosts[].mounts[].default",
@@ -68,6 +69,7 @@ enum lejp_vhost_paths {
 	LEJPVP_HOST_SSL_KEY,
 	LEJPVP_HOST_SSL_CERT,
 	LEJPVP_HOST_SSL_CA,
+	LEJPVP_ACCESS_LOG,
 	LEJPVP_MOUNTPOINT,
 	LEJPVP_ORIGIN,
 	LEJPVP_DEFAULT,
@@ -192,6 +194,7 @@ lejp_vhosts_cb(struct lejp_ctx *ctx, char reason)
 				       "!AES256-SHA256";
 		a->info->pvo = NULL;
 		a->info->keepalive_timeout = 60;
+		a->info->log_filepath = NULL;
 		a->info->options &= ~(LWS_SERVER_OPTION_UNIX_SOCK |
 				      LWS_SERVER_OPTION_STS);
 	}
@@ -298,6 +301,9 @@ lejp_vhosts_cb(struct lejp_ctx *ctx, char reason)
 	case LEJPVP_HOST_SSL_CA:
 		a->info->ssl_ca_filepath = a->p;
 		break;
+	case LEJPVP_ACCESS_LOG:
+		a->info->log_filepath = a->p;
+		break;
 	case LEJPVP_MOUNTPOINT:
 		a->mountpoint = a->p;
 		break;