add SoupServerFeature support to SoupLogger, use it in simple-httpdwip/server-features

2 files changed, 150 insertions, 64 deletions

diff --git a/examples/simple-httpd.c b/examples/simple-httpd.c
index f3be82e1..6abe5c2e 100644
--- a/examples/simple-httpd.c
+++ b/examples/simple-httpd.c
@@ -183,16 +183,6 @@ server_callback (SoupServer *server, SoupMessage *msg,
 		 SoupClientContext *context, gpointer data)
 {
 	char *file_path;
-	SoupMessageHeadersIter iter;
-	const char *name, *value;
-
-	g_print ("%s %s HTTP/1.%d\n", msg->method, path,
-		 soup_message_get_http_version (msg));
-	soup_message_headers_iter_init (&iter, msg->request_headers);
-	while (soup_message_headers_iter_next (&iter, &name, &value))
-		g_print ("%s: %s\n", name, value);
-	if (msg->request_body->length)
-		g_print ("%s\n", msg->request_body->data);
 
 	file_path = g_strdup_printf (".%s", path);
 
@@ -204,7 +194,6 @@ server_callback (SoupServer *server, SoupMessage *msg,
 		soup_message_set_status (msg, SOUP_STATUS_NOT_IMPLEMENTED);
 
 	g_free (file_path);
-	g_print ("  -> %d %s\n\n", msg->status_code, msg->reason_phrase);
 }
 
 static void
@@ -239,6 +228,7 @@ main (int argc, char **argv)
 	GSList *uris, *u;
 	char *str;
 	GTlsCertificate *cert;
+	SoupLogger *logger;
 	GError *error = NULL;
 
 	opts = g_option_context_new (NULL);
@@ -280,6 +270,10 @@ main (int argc, char **argv)
 	soup_server_add_handler (server, NULL,
 				 server_callback, NULL, NULL);
 
+	logger = soup_logger_new (SOUP_LOGGER_LOG_BODY, -1);
+	soup_server_add_feature (server, SOUP_SERVER_FEATURE (logger));
+	g_object_unref (logger);
+
 	uris = soup_server_get_uris (server);
 	for (u = uris; u; u = u->next) {
 		str = soup_uri_to_string (u->data, FALSE);
diff --git a/libsoup/soup-logger.c b/libsoup/soup-logger.c
index 34a55764..50c1e7b7 100644
--- a/libsoup/soup-logger.c
+++ b/libsoup/soup-logger.c
@@ -21,16 +21,18 @@
  * SECTION:soup-logger
  * @short_description: Debug logging support
  *
- * #SoupLogger watches a #SoupSession and logs the HTTP traffic that
- * it generates, for debugging purposes. Many applications use an
- * environment variable to determine whether or not to use
- * #SoupLogger, and to determine the amount of debugging output.
+ * #SoupLogger watches a #SoupSession or #SoupServer and logs the HTTP
+ * traffic that it generates, for debugging purposes. Many
+ * applications use an environment variable to determine whether or
+ * not to use #SoupLogger, and to determine the amount of debugging
+ * output.
  *
  * To use #SoupLogger, first create a logger with soup_logger_new(),
  * optionally configure it with soup_logger_set_request_filter(),
  * soup_logger_set_response_filter(), and soup_logger_set_printer(),
  * and then attach it to a session (or multiple sessions) with
- * soup_session_add_feature().
+ * soup_session_add_feature(), or to a server with
+ * soup_server_add_feature().
  *
  * By default, the debugging output is sent to
  * <literal>stdout</literal>, and looks something like:
@@ -57,19 +59,19 @@
  * received.
  *
  * The <literal>Soup-Debug</literal> line gives further debugging
- * information about the #SoupSession, #SoupMessage, and #SoupSocket
- * involved; the hex numbers are the addresses of the objects in
- * question (which may be useful if you are running in a debugger).
- * The decimal IDs are simply counters that uniquely identify objects
- * across the lifetime of the #SoupLogger. In particular, this can be
- * used to identify when multiple messages are sent across the same
- * connection.
+ * information about the #SoupSession (or #SoupServer), #SoupMessage,
+ * and #SoupSocket involved; the hex numbers are the addresses of the
+ * objects in question (which may be useful if you are running in a
+ * debugger). The decimal IDs are simply counters that uniquely
+ * identify objects across the lifetime of the #SoupLogger. In
+ * particular, this can be used to identify when multiple messages are
+ * sent across the same connection.
  *
- * Currently, the request half of the message is logged just before
- * the first byte of the request gets written to the network (from the
- * #SoupSession::request_started signal), which means that if you have
- * not made the complete request body available at that point, it will
- * not be logged.
+ * Currently, for client-side logging, the request half of the message
+ * is logged just before the first byte of the request gets written to
+ * the network (from the #SoupSession::request_started signal), which
+ * means that if you have not made the complete request body available
+ * at that point, it will not be logged.
  *
  * The response is logged just after the last byte of the response
  * body is read from the network (from the #SoupMessage::got_body or
@@ -87,10 +89,13 @@
  **/
 
 static void soup_logger_session_feature_init (SoupSessionFeatureInterface *feature_interface, gpointer interface_data);
+static void soup_logger_server_feature_init (SoupServerFeatureInterface *feature_interface, gpointer interface_data);
 
 G_DEFINE_TYPE_WITH_CODE (SoupLogger, soup_logger, G_TYPE_OBJECT,
 			 G_IMPLEMENT_INTERFACE (SOUP_TYPE_SESSION_FEATURE,
-						soup_logger_session_feature_init))
+						soup_logger_session_feature_init)
+			 G_IMPLEMENT_INTERFACE (SOUP_TYPE_SERVER_FEATURE,
+						soup_logger_server_feature_init))
 
 typedef struct {
 	/* We use a mutex so that if requests are being run in
@@ -443,7 +448,7 @@ soup_logger_print_basic_auth (SoupLogger *logger, const char *value)
 
 static void
 print_request (SoupLogger *logger, SoupMessage *msg,
-	       SoupSession *session, SoupSocket *socket,
+	       gpointer owner, SoupSocket *socket,
 	       gboolean restarted)
 {
 	SoupLoggerPrivate *priv = SOUP_LOGGER_GET_PRIVATE (logger);
@@ -481,8 +486,8 @@ print_request (SoupLogger *logger, SoupMessage *msg,
 			   (unsigned long)time (0));
 	soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, '>',
 			   "Soup-Debug: %s %u (%p), %s %u (%p), %s %u (%p)%s",
-			   g_type_name_from_instance ((GTypeInstance *)session),
-			   soup_logger_get_id (logger, session), session,
+			   g_type_name_from_instance ((GTypeInstance *)owner),
+			   soup_logger_get_id (logger, owner), owner,
 			   g_type_name_from_instance ((GTypeInstance *)msg),
 			   soup_logger_get_id (logger, msg), msg,
 			   g_type_name_from_instance ((GTypeInstance *)socket),
@@ -579,14 +584,18 @@ print_response (SoupLogger *logger, SoupMessage *msg)
 	if (log_level == SOUP_LOGGER_LOG_HEADERS)
 		return;
 
-	if (msg->response_body->data) {
+	if (msg->response_body->length) {
+		if (!msg->response_body->data) {
+			SoupBuffer *body = soup_message_body_flatten (msg->response_body);
+			soup_buffer_free (body);
+		}
 		soup_logger_print (logger, SOUP_LOGGER_LOG_BODY, '<',
 				   "\n%s", msg->response_body->data);
 	}
 }
 
 static void
-finished (SoupMessage *msg, gpointer user_data)
+do_print_response (SoupMessage *msg, gpointer user_data)
 {
 	SoupLogger *logger = user_data;
 	SoupLoggerPrivate *priv = SOUP_LOGGER_GET_PRIVATE (logger);
@@ -600,7 +609,15 @@ finished (SoupMessage *msg, gpointer user_data)
 }
 
 static void
-got_informational (SoupMessage *msg, gpointer user_data)
+finished (SoupMessage *msg, gpointer user_data)
+{
+	SoupLogger *logger = user_data;
+
+	do_print_response (msg, logger);
+}
+
+static void
+client_got_informational (SoupMessage *msg, gpointer user_data)
 {
 	SoupLogger *logger = user_data;
 	SoupLoggerPrivate *priv = SOUP_LOGGER_GET_PRIVATE (logger);
@@ -635,43 +652,34 @@ got_informational (SoupMessage *msg, gpointer user_data)
 }
 
 static void
-got_body (SoupMessage *msg, gpointer user_data)
+client_got_body (SoupMessage *msg, gpointer user_data)
 {
 	SoupLogger *logger = user_data;
-	SoupLoggerPrivate *priv = SOUP_LOGGER_GET_PRIVATE (logger);
-
-	g_mutex_lock (&priv->lock);
 
 	g_signal_handlers_disconnect_by_func (msg, finished, logger);
-	print_response (logger, msg);
-	soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, ' ', "");
-
-	g_mutex_unlock (&priv->lock);
+	do_print_response (msg, logger);
 }
 
 static void
-soup_logger_request_queued (SoupSessionFeature *logger,
-			    SoupSession *session,
-			    SoupMessage *msg)
+soup_logger_session_request_queued (SoupSessionFeature *logger,
+				    SoupSession *session,
+				    SoupMessage *msg)
 {
 	g_return_if_fail (SOUP_IS_MESSAGE (msg));
 
 	g_signal_connect (msg, "got-informational",
-			  G_CALLBACK (got_informational),
-			  logger);
+			  G_CALLBACK (client_got_informational), logger);
 	g_signal_connect (msg, "got-body",
-			  G_CALLBACK (got_body),
-			  logger);
+			  G_CALLBACK (client_got_body), logger);
 	g_signal_connect (msg, "finished",
-			  G_CALLBACK (finished),
-			  logger);
+			  G_CALLBACK (finished), logger);
 }
 
 static void
-soup_logger_request_started (SoupSessionFeature *feature,
-			     SoupSession *session,
-			     SoupMessage *msg,
-			     SoupSocket *socket)
+soup_logger_session_request_started (SoupSessionFeature *feature,
+				     SoupSession *session,
+				     SoupMessage *msg,
+				     SoupSocket *socket)
 {
 	SoupLogger *logger = SOUP_LOGGER (feature);
 	gboolean restarted;
@@ -700,22 +708,106 @@ soup_logger_request_started (SoupSessionFeature *feature,
 }
 
 static void
-soup_logger_request_unqueued (SoupSessionFeature *logger,
-			      SoupSession *session,
-			      SoupMessage *msg)
+soup_logger_session_request_unqueued (SoupSessionFeature *logger,
+				      SoupSession *session,
+				      SoupMessage *msg)
 {
 	g_return_if_fail (SOUP_IS_MESSAGE (msg));
 
-	g_signal_handlers_disconnect_by_func (msg, got_informational, logger);
-	g_signal_handlers_disconnect_by_func (msg, got_body, logger);
+	g_signal_handlers_disconnect_by_func (msg, client_got_informational, logger);
+	g_signal_handlers_disconnect_by_func (msg, client_got_body, logger);
 	g_signal_handlers_disconnect_by_func (msg, finished, logger);
 }
 
 static void
+server_got_headers (SoupMessage *msg, gpointer user_data)
+{
+	SoupLogger *logger = user_data;
+	SoupLoggerPrivate *priv = SOUP_LOGGER_GET_PRIVATE (logger);
+	SoupServer *server;
+	SoupSocket *socket;
+
+	/* Normally we print the request from the got-body handler.
+	 * We only need to do something here in the expect-continue
+	 * case.
+	 */
+	if (!(soup_message_headers_get_expectations (msg->request_headers) &
+	      SOUP_EXPECTATION_CONTINUE))
+		return;
+
+	g_mutex_lock (&priv->lock);
+
+	server = g_object_get_data (G_OBJECT (msg), "SoupLogger-server");
+	socket = g_object_get_data (G_OBJECT (msg), "SoupLogger-socket");
+	print_request (logger, msg, server, socket, FALSE);
+	soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, ' ', "");
+
+	g_mutex_unlock (&priv->lock);
+}
+
+static void
+server_got_body (SoupMessage *msg, gpointer user_data)
+{
+	SoupLogger *logger = user_data;
+	SoupLoggerPrivate *priv = SOUP_LOGGER_GET_PRIVATE (logger);
+	SoupServer *server;
+	SoupSocket *socket;
+
+	g_mutex_lock (&priv->lock);
+
+	server = g_object_get_data (G_OBJECT (msg), "SoupLogger-server");
+	socket = g_object_get_data (G_OBJECT (msg), "SoupLogger-socket");
+	print_request (logger, msg, server, socket, FALSE);
+	soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, ' ', "");
+
+	g_mutex_unlock (&priv->lock);
+}
+
+static void
+soup_logger_server_request_started (SoupServerFeature *feature,
+				    SoupServer *server,
+				    SoupMessage *msg,
+				    SoupClientContext *client)
+{
+	SoupLogger *logger = SOUP_LOGGER (feature);
+	SoupSocket *socket;
+
+	g_return_if_fail (SOUP_IS_SERVER (server));
+	g_return_if_fail (SOUP_IS_MESSAGE (msg));
+	g_return_if_fail (client != NULL);
+
+	socket = soup_client_context_get_socket (client);
+	soup_logger_set_id (logger, msg);
+	if (!soup_logger_get_id (logger, server))
+		soup_logger_set_id (logger, server);
+	if (!soup_logger_get_id (logger, socket))
+		soup_logger_set_id (logger, socket);
+
+	g_object_set_data (G_OBJECT (msg), "SoupLogger-server", server);
+	g_object_set_data (G_OBJECT (msg), "SoupLogger-socket", socket);
+
+	g_signal_connect (msg, "got-headers",
+			  G_CALLBACK (server_got_headers), logger);
+	g_signal_connect (msg, "got-body",
+			  G_CALLBACK (server_got_body), logger);
+	g_signal_connect (msg, "wrote-informational",
+			  G_CALLBACK (do_print_response), logger);
+	g_signal_connect (msg, "wrote-body",
+			  G_CALLBACK (do_print_response), logger);
+}
+
+static void
 soup_logger_session_feature_init (SoupSessionFeatureInterface *feature_interface,
 				  gpointer interface_data)
 {
-	feature_interface->request_queued = soup_logger_request_queued;
-	feature_interface->request_started = soup_logger_request_started;
-	feature_interface->request_unqueued = soup_logger_request_unqueued;
+	feature_interface->request_queued = soup_logger_session_request_queued;
+	feature_interface->request_started = soup_logger_session_request_started;
+	feature_interface->request_unqueued = soup_logger_session_request_unqueued;
+}
+
+static void
+soup_logger_server_feature_init (SoupServerFeatureInterface *feature_interface,
+				 gpointer interface_data)
+{
+	feature_interface->request_started = soup_logger_server_request_started;
 }