[libsoup] logger: re-add support for logging request/response bodies
- From: Carlos Garcia Campos <carlosgc src gnome org>
- To: commits-list gnome org
- Cc:
- Subject: [libsoup] logger: re-add support for logging request/response bodies
- Date: Tue, 9 Mar 2021 13:33:32 +0000 (UTC)
commit c61f62f9bae4a78f38266b41fc3af1a4acb2c929
Author: Daniel Kolesa <dkolesa igalia com>
Date: Thu Mar 4 13:31:17 2021 +0100
logger: re-add support for logging request/response bodies
docs/reference/libsoup-3.0-sections.txt | 2 +
docs/reference/meson.build | 2 +
libsoup/meson.build | 1 +
libsoup/soup-body-output-stream.c | 12 +-
libsoup/soup-logger-input-stream.c | 229 ++++++++++++++++++++++++++
libsoup/soup-logger-input-stream.h | 21 +++
libsoup/soup-logger-private.h | 14 ++
libsoup/soup-logger.c | 279 ++++++++++++++++++++++++++++++--
libsoup/soup-logger.h | 10 +-
libsoup/soup-message-io.c | 11 +-
tests/logger-test.c | 201 +++++++++++++++++++++--
tests/test-utils.c | 2 +-
12 files changed, 751 insertions(+), 33 deletions(-)
---
diff --git a/docs/reference/libsoup-3.0-sections.txt b/docs/reference/libsoup-3.0-sections.txt
index 0d996bae..0e963653 100644
--- a/docs/reference/libsoup-3.0-sections.txt
+++ b/docs/reference/libsoup-3.0-sections.txt
@@ -553,6 +553,8 @@ soup_form_encode_valist
SoupLogger
SoupLoggerLogLevel
soup_logger_new
+soup_logger_set_max_body_size
+soup_logger_get_max_body_size
<SUBSECTION>
SoupLoggerFilter
soup_logger_set_request_filter
diff --git a/docs/reference/meson.build b/docs/reference/meson.build
index 812042fa..40a98944 100644
--- a/docs/reference/meson.build
+++ b/docs/reference/meson.build
@@ -23,6 +23,8 @@ ignore_headers = [
'soup-cookie-jar-sqlite.h',
'soup-cache-private.h',
'soup-cache-client-input-stream.h',
+ 'soup-logger-input-stream.h',
+ 'soup-logger-private.h',
'soup-socket.h',
'soup-socket-properties.h',
'soup-websocket-extension-manager-private.h',
diff --git a/libsoup/meson.build b/libsoup/meson.build
index 48b8e596..827c4a3b 100644
--- a/libsoup/meson.build
+++ b/libsoup/meson.build
@@ -59,6 +59,7 @@ soup_sources = [
'soup-init.c',
'soup-io-stream.c',
'soup-logger.c',
+ 'soup-logger-input-stream.c',
'soup-message.c',
'soup-message-headers.c',
'soup-message-io.c',
diff --git a/libsoup/soup-body-output-stream.c b/libsoup/soup-body-output-stream.c
index a390ed83..c1c0e4a0 100644
--- a/libsoup/soup-body-output-stream.c
+++ b/libsoup/soup-body-output-stream.c
@@ -115,9 +115,10 @@ soup_body_output_stream_get_property (GObject *object, guint prop_id,
static void
soup_body_output_stream_wrote_data (SoupBodyOutputStream *bostream,
- gsize count)
+ const void *buffer,
+ gsize count)
{
- g_signal_emit (bostream, signals[WROTE_DATA], 0, count);
+ g_signal_emit (bostream, signals[WROTE_DATA], 0, buffer, count);
}
static gssize
@@ -150,7 +151,7 @@ soup_body_output_stream_write_raw (SoupBodyOutputStream *bostream,
if (nwrote > 0 && priv->write_length) {
priv->written += nwrote;
- soup_body_output_stream_wrote_data (bostream, nwrote);
+ soup_body_output_stream_wrote_data (bostream, buffer, nwrote);
}
if (nwrote == my_count && my_count != count)
@@ -199,7 +200,7 @@ again:
buffer, count, blocking,
cancellable, error);
if (nwrote > 0)
- soup_body_output_stream_wrote_data (bostream, nwrote);
+ soup_body_output_stream_wrote_data (bostream, buffer, nwrote);
if (nwrote < (gssize)count)
return nwrote;
@@ -340,7 +341,8 @@ soup_body_output_stream_class_init (SoupBodyOutputStreamClass *stream_class)
0,
NULL, NULL,
NULL,
- G_TYPE_NONE, 1,
+ G_TYPE_NONE, 2,
+ G_TYPE_POINTER,
G_TYPE_UINT);
g_object_class_install_property (
diff --git a/libsoup/soup-logger-input-stream.c b/libsoup/soup-logger-input-stream.c
new file mode 100644
index 00000000..6b7c6100
--- /dev/null
+++ b/libsoup/soup-logger-input-stream.c
@@ -0,0 +1,229 @@
+/* soup-logger-stream.c
+ *
+ * Copyright (C) 2021 Igalia S.L.
+ */
+
+#include <string.h>
+
+#include "soup-logger-input-stream.h"
+#include "soup.h"
+
+enum {
+ PROP_LOGGER = 1
+};
+
+enum {
+ READ_DATA,
+ LAST_SIGNAL
+};
+
+static guint signals[LAST_SIGNAL] = { 0 };
+
+struct _SoupLoggerInputStream {
+ GFilterInputStream parent;
+};
+
+typedef struct {
+ SoupLogger *logger;
+ GByteArray *buffer; /* for skip; we still need to log it */
+} SoupLoggerInputStreamPrivate;
+
+static void soup_logger_input_stream_pollable_init (GPollableInputStreamInterface *pollable_interface,
gpointer interface_data);
+
+G_DEFINE_TYPE_WITH_CODE (SoupLoggerInputStream, soup_logger_input_stream, G_TYPE_FILTER_INPUT_STREAM,
+ G_ADD_PRIVATE (SoupLoggerInputStream)
+ G_IMPLEMENT_INTERFACE (G_TYPE_POLLABLE_INPUT_STREAM,
+ soup_logger_input_stream_pollable_init))
+
+static void
+soup_logger_input_stream_init (SoupLoggerInputStream *logger)
+{
+}
+
+static void
+soup_logger_input_stream_finalize (GObject *object)
+{
+ SoupLoggerInputStream *stream = SOUP_LOGGER_INPUT_STREAM (object);
+ SoupLoggerInputStreamPrivate *priv = soup_logger_input_stream_get_instance_private (stream);
+
+ g_clear_object (&priv->logger);
+
+ g_clear_pointer (&priv->buffer, g_byte_array_unref);
+
+ G_OBJECT_CLASS (soup_logger_input_stream_parent_class)->finalize (object);
+}
+
+static void
+soup_logger_input_stream_set_property (GObject *object, guint prop_id,
+ const GValue *value, GParamSpec *pspec)
+{
+ SoupLoggerInputStream *stream = SOUP_LOGGER_INPUT_STREAM (object);
+ SoupLoggerInputStreamPrivate *priv = soup_logger_input_stream_get_instance_private (stream);
+
+ switch (prop_id) {
+ case PROP_LOGGER:
+ priv->logger = g_value_dup_object (value);
+ break;
+ default:
+ G_OBJECT_WARN_INVALID_PROPERTY_ID (object, prop_id, pspec);
+ break;
+ }
+}
+
+static void
+soup_logger_input_stream_get_property (GObject *object, guint prop_id,
+ GValue *value, GParamSpec *pspec)
+{
+ SoupLoggerInputStream *stream = SOUP_LOGGER_INPUT_STREAM (object);
+ SoupLoggerInputStreamPrivate *priv = soup_logger_input_stream_get_instance_private (stream);
+
+ switch (prop_id) {
+ case PROP_LOGGER:
+ g_value_set_object (value, priv->logger);
+ break;
+ default:
+ G_OBJECT_WARN_INVALID_PROPERTY_ID (object, prop_id, pspec);
+ break;
+ }
+}
+
+static gssize
+read_internal (GInputStream *stream,
+ void *buffer,
+ gsize count,
+ gboolean blocking,
+ GCancellable *cancellable,
+ GError **error)
+{
+ SoupLoggerInputStream *lstream = SOUP_LOGGER_INPUT_STREAM (stream);
+ gssize nread;
+
+ nread = g_pollable_stream_read (G_FILTER_INPUT_STREAM (stream)->base_stream,
+ buffer, count, blocking, cancellable, error);
+
+ if (nread > 0)
+ g_signal_emit (lstream, signals[READ_DATA], 0, buffer, nread);
+
+ return nread;
+}
+
+static gssize
+soup_logger_input_stream_read (GInputStream *stream,
+ void *buffer,
+ gsize count,
+ GCancellable *cancellable,
+ GError **error)
+{
+ return read_internal (stream, buffer, count, TRUE, cancellable, error);
+}
+
+static gssize
+soup_logger_input_stream_skip (GInputStream *stream,
+ gsize count,
+ GCancellable *cancellable,
+ GError **error)
+{
+ SoupLoggerInputStream *lstream = SOUP_LOGGER_INPUT_STREAM (stream);
+ SoupLoggerInputStreamPrivate *priv = soup_logger_input_stream_get_instance_private (lstream);
+
+ if (!priv->buffer)
+ priv->buffer = g_byte_array_sized_new (count);
+ else
+ g_byte_array_set_size (priv->buffer, count);
+
+ return read_internal (stream, priv->buffer->data, count, TRUE, cancellable, error);
+}
+
+static gboolean
+soup_logger_input_stream_can_poll (GPollableInputStream *stream)
+{
+ GInputStream *base_stream = G_FILTER_INPUT_STREAM (stream)->base_stream;
+
+ return G_IS_POLLABLE_INPUT_STREAM (base_stream) &&
+ g_pollable_input_stream_can_poll (G_POLLABLE_INPUT_STREAM (base_stream));
+}
+
+static gboolean
+soup_logger_input_stream_is_readable (GPollableInputStream *stream)
+{
+ return g_pollable_input_stream_is_readable (G_POLLABLE_INPUT_STREAM (G_FILTER_INPUT_STREAM
(stream)->base_stream));
+}
+
+static gssize
+soup_logger_input_stream_read_nonblocking (GPollableInputStream *stream,
+ void *buffer,
+ gsize count,
+ GError **error)
+{
+ return read_internal (G_INPUT_STREAM (stream),
+ buffer, count, FALSE, NULL, error);
+}
+
+static GSource *
+soup_logger_input_stream_create_source (GPollableInputStream *stream,
+ GCancellable *cancellable)
+{
+ GSource *base_source, *pollable_source;
+
+ base_source = g_pollable_input_stream_create_source (G_POLLABLE_INPUT_STREAM (G_FILTER_INPUT_STREAM
(stream)->base_stream),
+ cancellable);
+
+ g_source_set_dummy_callback (base_source);
+ pollable_source = g_pollable_source_new (G_OBJECT (stream));
+ g_source_add_child_source (pollable_source, base_source);
+ g_source_unref (base_source);
+
+ return pollable_source;
+}
+
+static void
+soup_logger_input_stream_class_init (SoupLoggerInputStreamClass *klass)
+{
+ GObjectClass *object_class = G_OBJECT_CLASS (klass);
+ GInputStreamClass *input_stream_class = G_INPUT_STREAM_CLASS (klass);
+
+ object_class->finalize = soup_logger_input_stream_finalize;
+ object_class->set_property = soup_logger_input_stream_set_property;
+ object_class->get_property = soup_logger_input_stream_get_property;
+
+ input_stream_class->read_fn = soup_logger_input_stream_read;
+ input_stream_class->skip = soup_logger_input_stream_skip;
+
+ signals[READ_DATA] =
+ g_signal_new ("read-data",
+ G_OBJECT_CLASS_TYPE (object_class),
+ G_SIGNAL_RUN_LAST,
+ 0,
+ NULL, NULL,
+ NULL,
+ G_TYPE_NONE,
+ 2,
+ G_TYPE_POINTER, G_TYPE_INT);
+
+ g_object_class_install_property (
+ object_class, PROP_LOGGER,
+ g_param_spec_object ("logger",
+ "Logger",
+ "The stream's SoupLogger",
+ SOUP_TYPE_LOGGER,
+ G_PARAM_READWRITE | G_PARAM_CONSTRUCT_ONLY |
+ G_PARAM_STATIC_STRINGS));
+}
+
+static void
+soup_logger_input_stream_pollable_init (GPollableInputStreamInterface *interface,
+ gpointer interface_data)
+{
+ interface->can_poll = soup_logger_input_stream_can_poll;
+ interface->is_readable = soup_logger_input_stream_is_readable;
+ interface->read_nonblocking = soup_logger_input_stream_read_nonblocking;
+ interface->create_source = soup_logger_input_stream_create_source;
+}
+
+SoupLogger *
+soup_logger_input_stream_get_logger (SoupLoggerInputStream *stream)
+{
+ SoupLoggerInputStreamPrivate *priv = soup_logger_input_stream_get_instance_private (stream);
+
+ return priv->logger;
+}
diff --git a/libsoup/soup-logger-input-stream.h b/libsoup/soup-logger-input-stream.h
new file mode 100644
index 00000000..8a3a91d2
--- /dev/null
+++ b/libsoup/soup-logger-input-stream.h
@@ -0,0 +1,21 @@
+/*
+ * Copyright (C) 2021 Igalia S.L.
+ */
+
+#pragma once
+
+#include "soup-types.h"
+#include "soup-logger.h"
+
+G_BEGIN_DECLS
+
+#define SOUP_TYPE_LOGGER_INPUT_STREAM (soup_logger_input_stream_get_type ())
+G_DECLARE_FINAL_TYPE (SoupLoggerInputStream,
+ soup_logger_input_stream,
+ SOUP,
+ LOGGER_INPUT_STREAM,
+ GFilterInputStream)
+
+SoupLogger *soup_logger_input_stream_get_logger (SoupLoggerInputStream *stream);
+
+G_END_DECLS
diff --git a/libsoup/soup-logger-private.h b/libsoup/soup-logger-private.h
new file mode 100644
index 00000000..8307319a
--- /dev/null
+++ b/libsoup/soup-logger-private.h
@@ -0,0 +1,14 @@
+/*
+ * Copyright (C) 2021 Igalia S.L.
+ */
+
+#pragma once
+
+#include "soup-logger.h"
+#include "soup-body-output-stream.h"
+
+G_BEGIN_DECLS
+
+void soup_logger_request_body_setup (SoupLogger *logger, SoupMessage *msg);
+
+G_END_DECLS
diff --git a/libsoup/soup-logger.c b/libsoup/soup-logger.c
index 72afb012..e7a20d71 100644
--- a/libsoup/soup-logger.c
+++ b/libsoup/soup-logger.c
@@ -14,7 +14,8 @@
#include <stdio.h>
#include <string.h>
-#include "soup-logger.h"
+#include "soup-logger-private.h"
+#include "soup-logger-input-stream.h"
#include "soup-connection.h"
#include "soup-message-private.h"
#include "soup-misc.h"
@@ -99,9 +100,13 @@ struct _SoupLogger {
typedef struct {
GQuark tag;
GHashTable *ids;
+ GHashTable *request_bodies;
+ GHashTable *request_messages;
+ GHashTable *response_bodies;
SoupSession *session;
SoupLoggerLogLevel level;
+ int max_body_size;
SoupLoggerFilter request_filter;
gpointer request_filter_data;
@@ -120,16 +125,114 @@ enum {
PROP_0,
PROP_LEVEL,
+ PROP_MAX_BODY_SIZE,
LAST_PROP
};
+static void body_ostream_done (gpointer data, GObject *bostream);
+
static void soup_logger_session_feature_init (SoupSessionFeatureInterface *feature_interface, gpointer
interface_data);
+static SoupContentProcessorInterface *soup_logger_default_content_processor_interface;
+static void soup_logger_content_processor_init (SoupContentProcessorInterface *interface, gpointer
interface_data);
+
G_DEFINE_TYPE_WITH_CODE (SoupLogger, soup_logger, G_TYPE_OBJECT,
G_ADD_PRIVATE (SoupLogger)
G_IMPLEMENT_INTERFACE (SOUP_TYPE_SESSION_FEATURE,
- soup_logger_session_feature_init))
+ soup_logger_session_feature_init)
+ G_IMPLEMENT_INTERFACE (SOUP_TYPE_CONTENT_PROCESSOR,
+ soup_logger_content_processor_init))
+
+static void
+write_body (SoupLogger *logger, const char *buffer, gsize nread,
+ gpointer key, GHashTable *bodies)
+{
+ SoupLoggerPrivate *priv = soup_logger_get_instance_private (logger);
+ GString *body;
+
+ if (!nread)
+ return;
+
+ body = g_hash_table_lookup (bodies, key);
+
+ if (!body) {
+ body = g_string_new (NULL);
+ g_hash_table_insert (bodies, key, body);
+ }
+
+ if (priv->max_body_size > 0) {
+ /* longer than max => we've written the extra [...] */
+ if (body->len > priv->max_body_size)
+ return;
+ int cap = priv->max_body_size - body->len;
+ if (cap)
+ g_string_append_len (body, buffer,
+ (nread < cap) ? nread : cap);
+ if (nread > cap)
+ g_string_append (body, "\n[...]");
+ } else {
+ g_string_append_len (body, buffer, nread);
+ }
+}
+
+static void
+write_response_body (SoupLoggerInputStream *stream, char *buffer, gsize nread,
+ gpointer user_data)
+{
+ SoupLogger *logger = soup_logger_input_stream_get_logger (stream);
+ SoupLoggerPrivate *priv = soup_logger_get_instance_private (logger);
+
+ write_body (logger, buffer, nread, user_data, priv->response_bodies);
+}
+
+static GInputStream *
+soup_logger_content_processor_wrap_input (SoupContentProcessor *processor,
+ GInputStream *base_stream,
+ SoupMessage *msg,
+ GError **error)
+{
+ SoupLogger *logger = SOUP_LOGGER (processor);
+ SoupLoggerPrivate *priv = soup_logger_get_instance_private (logger);
+ SoupLoggerInputStream *stream;
+ SoupLoggerLogLevel log_level;
+
+ if (priv->request_filter)
+ log_level = priv->request_filter (logger, msg,
+ priv->response_filter_data);
+ else
+ log_level = priv->level;
+
+ if (log_level < SOUP_LOGGER_LOG_BODY)
+ return NULL;
+
+ stream = g_object_new (SOUP_TYPE_LOGGER_INPUT_STREAM,
+ "base-stream", base_stream,
+ "logger", logger,
+ NULL);
+
+ g_signal_connect_object (stream, "read-data",
+ G_CALLBACK (write_response_body), msg, 0);
+
+ return G_INPUT_STREAM (stream);
+}
+
+static void
+soup_logger_content_processor_init (SoupContentProcessorInterface *interface,
+ gpointer interface_data)
+{
+ soup_logger_default_content_processor_interface =
+ g_type_default_interface_peek (SOUP_TYPE_CONTENT_PROCESSOR);
+
+ interface->processing_stage = SOUP_STAGE_BODY_DATA;
+ interface->wrap_input = soup_logger_content_processor_wrap_input;
+}
+
+static void
+body_free (gpointer str)
+{
+ g_string_free (str, TRUE);
+}
static void
soup_logger_init (SoupLogger *logger)
@@ -141,6 +244,15 @@ soup_logger_init (SoupLogger *logger)
priv->tag = g_quark_from_string (id);
g_free (id);
priv->ids = g_hash_table_new (NULL, NULL);
+ priv->request_bodies = g_hash_table_new_full (NULL, NULL, NULL, body_free);
+ priv->response_bodies = g_hash_table_new_full (NULL, NULL, NULL, body_free);
+ priv->request_messages = g_hash_table_new (NULL, NULL);
+}
+
+static void
+body_ostream_drop_ref (gpointer key, gpointer value, gpointer data)
+{
+ g_object_weak_unref (key, body_ostream_done, data);
}
static void
@@ -149,7 +261,13 @@ soup_logger_finalize (GObject *object)
SoupLogger *logger = SOUP_LOGGER (object);
SoupLoggerPrivate *priv = soup_logger_get_instance_private (logger);
+ g_hash_table_foreach (priv->request_messages,
+ body_ostream_drop_ref, priv);
+
g_hash_table_destroy (priv->ids);
+ g_hash_table_destroy (priv->request_bodies);
+ g_hash_table_destroy (priv->response_bodies);
+ g_hash_table_destroy (priv->request_messages);
if (priv->request_filter_dnotify)
priv->request_filter_dnotify (priv->request_filter_data);
@@ -172,6 +290,9 @@ soup_logger_set_property (GObject *object, guint prop_id,
case PROP_LEVEL:
priv->level = g_value_get_enum (value);
break;
+ case PROP_MAX_BODY_SIZE:
+ priv->max_body_size = g_value_get_int (value);
+ break;
default:
G_OBJECT_WARN_INVALID_PROPERTY_ID (object, prop_id, pspec);
break;
@@ -189,6 +310,9 @@ soup_logger_get_property (GObject *object, guint prop_id,
case PROP_LEVEL:
g_value_set_enum (value, priv->level);
break;
+ case PROP_MAX_BODY_SIZE:
+ g_value_set_int (value, priv->max_body_size);
+ break;
default:
G_OBJECT_WARN_INVALID_PROPERTY_ID (object, prop_id, pspec);
break;
@@ -220,6 +344,24 @@ soup_logger_class_init (SoupLoggerClass *logger_class)
SOUP_LOGGER_LOG_MINIMAL,
G_PARAM_READWRITE |
G_PARAM_STATIC_STRINGS));
+ /**
+ * SoupLogger:max-body-size:
+ *
+ * If #SoupLogger:level is %SOUP_LOGGER_LOG_BODY, this gives
+ * the maximum number of bytes of the body that will be logged.
+ * (-1 means "no limit".)
+ *
+ **/
+ g_object_class_install_property (
+ object_class, PROP_MAX_BODY_SIZE,
+ g_param_spec_int ("max-body-size",
+ "Max Body Size",
+ "The maximum body size to output",
+ -1,
+ G_MAXINT,
+ -1,
+ G_PARAM_READWRITE |
+ G_PARAM_STATIC_STRINGS));
}
/**
@@ -228,6 +370,7 @@ soup_logger_class_init (SoupLoggerClass *logger_class)
* @SOUP_LOGGER_LOG_MINIMAL: Log the Request-Line or Status-Line and
* the Soup-Debug pseudo-headers
* @SOUP_LOGGER_LOG_HEADERS: Log the full request/response headers
+ * @SOUP_LOGGER_LOG_BODY: Log the full headers and request/response bodies
*
* Describes the level of logging output to provide.
**/
@@ -364,6 +507,37 @@ soup_logger_set_printer (SoupLogger *logger,
priv->printer_dnotify = destroy;
}
+/**
+ * soup_logger_set_max_body_size:
+ * @logger: a #SoupLogger
+ * @max_body_size: the maximum body size to log
+ *
+ * Sets the maximum body size for @logger (-1 means no limit).
+ **/
+void
+soup_logger_set_max_body_size (SoupLogger *logger, int max_body_size)
+{
+ SoupLoggerPrivate *priv = soup_logger_get_instance_private (logger);
+
+ priv->max_body_size = max_body_size;
+}
+
+/**
+ * soup_logger_get_max_body_size:
+ * @logger: a #SoupLogger
+ *
+ * Get the maximum body size for @logger.
+ *
+ * Returns: the maximum body size, or -1 if unlimited
+ **/
+int
+soup_logger_get_max_body_size (SoupLogger *logger)
+{
+ SoupLoggerPrivate *priv = soup_logger_get_instance_private (logger);
+
+ return priv->max_body_size;
+}
+
static guint
soup_logger_get_id (SoupLogger *logger, gpointer object)
{
@@ -458,6 +632,7 @@ print_request (SoupLogger *logger, SoupMessage *msg,
SoupMessageHeadersIter iter;
const char *name, *value;
char *socket_dbg;
+ GString *body;
GUri *uri;
if (priv->request_filter) {
@@ -518,6 +693,19 @@ print_request (SoupLogger *logger, SoupMessage *msg,
"%s: %s", name, value);
}
}
+
+ if (log_level == SOUP_LOGGER_LOG_HEADERS)
+ return;
+
+ /* will be logged in get_informational */
+ if (soup_message_headers_get_expectations (soup_message_get_request_headers (msg)) ==
SOUP_EXPECTATION_CONTINUE)
+ return;
+
+ if (!g_hash_table_steal_extended (priv->request_bodies, msg, NULL, (gpointer *)&body))
+ return;
+
+ soup_logger_print (logger, SOUP_LOGGER_LOG_BODY, '>', "\n%s", body->str);
+ g_string_free (body, TRUE);
}
static void
@@ -527,6 +715,7 @@ print_response (SoupLogger *logger, SoupMessage *msg)
SoupLoggerLogLevel log_level;
SoupMessageHeadersIter iter;
const char *name, *value;
+ GString *body;
if (priv->response_filter) {
log_level = priv->response_filter (logger, msg,
@@ -558,6 +747,15 @@ print_response (SoupLogger *logger, SoupMessage *msg)
soup_logger_print (logger, SOUP_LOGGER_LOG_HEADERS, '<',
"%s: %s", name, value);
}
+
+ if (log_level == SOUP_LOGGER_LOG_HEADERS)
+ return;
+
+ if (!g_hash_table_steal_extended (priv->response_bodies, msg, NULL, (gpointer *)&body))
+ return;
+
+ soup_logger_print (logger, SOUP_LOGGER_LOG_BODY, '<', "\n%s", body->str);
+ g_string_free (body, TRUE);
}
static void
@@ -572,17 +770,37 @@ finished (SoupMessage *msg, gpointer user_data)
static void
got_informational (SoupMessage *msg, gpointer user_data)
{
- SoupLogger *logger = user_data;
+ SoupLogger *logger = user_data;
+ SoupLoggerPrivate *priv = soup_logger_get_instance_private (logger);
+ SoupLoggerLogLevel log_level;
+ GString *body = NULL;
- g_signal_handlers_disconnect_by_func (msg, finished, logger);
- print_response (logger, msg);
- soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, ' ', "\n");
+ if (priv->response_filter)
+ log_level = priv->response_filter (logger, msg,
+ priv->response_filter_data);
+ else
+ log_level = priv->level;
- if (soup_message_get_status (msg) == SOUP_STATUS_CONTINUE && soup_message_get_request_body_stream
(msg)) {
- soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, '>',
- "[Now sending request body...]");
- soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, ' ', "\n");
- }
+ g_signal_handlers_disconnect_by_func (msg, finished, logger);
+ print_response (logger, msg);
+ soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, ' ', "\n");
+
+ if (!g_hash_table_steal_extended (priv->response_bodies, msg, NULL, (gpointer *)&body))
+ return;
+
+ if (soup_message_get_status (msg) == SOUP_STATUS_CONTINUE) {
+ soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, '>',
+ "[Now sending request body...]");
+
+ if (log_level == SOUP_LOGGER_LOG_BODY) {
+ soup_logger_print (logger, SOUP_LOGGER_LOG_BODY,
+ '>', "%s", body->str);
+ }
+
+ soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, ' ', "\n");
+ }
+
+ g_string_free (body, TRUE);
}
static void
@@ -591,12 +809,45 @@ got_body (SoupMessage *msg, gpointer user_data)
SoupLogger *logger = user_data;
g_signal_handlers_disconnect_by_func (msg, finished, logger);
+
print_response (logger, msg);
soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, ' ', "\n");
}
static void
-starting (SoupMessage *msg, gpointer user_data)
+body_stream_wrote_data_cb (GOutputStream *stream, const void *buffer,
+ guint count, SoupLogger *logger)
+{
+ SoupLoggerPrivate *priv = soup_logger_get_instance_private (logger);
+ SoupMessage *msg = g_hash_table_lookup (priv->request_messages,
+ stream);
+
+ write_body (logger, buffer, count, msg, priv->request_bodies);
+}
+
+static void
+body_ostream_done (gpointer data, GObject *bostream)
+{
+ SoupLoggerPrivate *priv = data;
+
+ g_hash_table_remove (priv->request_messages, bostream);
+}
+
+void
+soup_logger_request_body_setup (SoupLogger *logger, SoupMessage *msg)
+{
+ SoupLoggerPrivate *priv = soup_logger_get_instance_private (logger);
+ SoupMessageIOData *io = (SoupMessageIOData *)soup_message_get_io_data (msg);
+
+ g_hash_table_insert (priv->request_messages, io->body_ostream, msg);
+ g_signal_connect_object (io->body_ostream, "wrote-data",
+ G_CALLBACK (body_stream_wrote_data_cb),
+ logger, 0);
+ g_object_weak_ref (G_OBJECT (io->body_ostream), body_ostream_done, priv);
+}
+
+static void
+wrote_body (SoupMessage *msg, gpointer user_data)
{
SoupLogger *logger = SOUP_LOGGER (user_data);
SoupLoggerPrivate *priv = soup_logger_get_instance_private (logger);
@@ -631,8 +882,8 @@ soup_logger_request_queued (SoupSessionFeature *logger,
{
g_return_if_fail (SOUP_IS_MESSAGE (msg));
- g_signal_connect_after (msg, "starting",
- G_CALLBACK (starting),
+ g_signal_connect (msg, "wrote-body",
+ G_CALLBACK (wrote_body),
logger);
g_signal_connect (msg, "got-informational",
G_CALLBACK (got_informational),
diff --git a/libsoup/soup-logger.h b/libsoup/soup-logger.h
index 7f0defba..03aa00e2 100644
--- a/libsoup/soup-logger.h
+++ b/libsoup/soup-logger.h
@@ -16,7 +16,8 @@ G_DECLARE_FINAL_TYPE (SoupLogger, soup_logger, SOUP, LOGGER, GObject)
typedef enum {
SOUP_LOGGER_LOG_NONE,
SOUP_LOGGER_LOG_MINIMAL,
- SOUP_LOGGER_LOG_HEADERS
+ SOUP_LOGGER_LOG_HEADERS,
+ SOUP_LOGGER_LOG_BODY
} SoupLoggerLogLevel;
typedef SoupLoggerLogLevel (*SoupLoggerFilter) (SoupLogger *logger,
@@ -50,4 +51,11 @@ void soup_logger_set_printer (SoupLogger *logger,
gpointer printer_data,
GDestroyNotify destroy);
+SOUP_AVAILABLE_IN_ALL
+void soup_logger_set_max_body_size (SoupLogger *logger,
+ int max_body_size);
+
+SOUP_AVAILABLE_IN_ALL
+int soup_logger_get_max_body_size (SoupLogger *logger);
+
G_END_DECLS
diff --git a/libsoup/soup-message-io.c b/libsoup/soup-message-io.c
index c4999df0..3b4d361c 100644
--- a/libsoup/soup-message-io.c
+++ b/libsoup/soup-message-io.c
@@ -23,6 +23,7 @@
#include "soup-content-processor.h"
#include "content-sniffer/soup-content-sniffer-stream.h"
#include "soup-filter-input-stream.h"
+#include "soup-logger-private.h"
#include "soup-message-private.h"
#include "soup-message-queue-item.h"
#include "soup-misc.h"
@@ -162,9 +163,10 @@ soup_message_setup_body_istream (GInputStream *body_stream,
static void
request_body_stream_wrote_data_cb (SoupMessage *msg,
- guint count)
+ const void *buffer,
+ guint count)
{
- soup_message_wrote_body_data (msg, count);
+ soup_message_wrote_body_data (msg, count);
}
static void
@@ -315,6 +317,7 @@ io_write (SoupMessage *msg, gboolean blocking,
{
SoupClientMessageIOData *client_io = soup_message_get_io_data (msg);
SoupMessageIOData *io = &client_io->base;
+ SoupSessionFeature *logger;
gssize nwrote;
if (io->async_error) {
@@ -365,6 +368,10 @@ io_write (SoupMessage *msg, gboolean blocking,
io->write_encoding,
io->write_length);
io->write_state = SOUP_MESSAGE_IO_STATE_BODY;
+ logger = soup_session_get_feature_for_message (client_io->item->session,
+ SOUP_TYPE_LOGGER, msg);
+ if (logger)
+ soup_logger_request_body_setup (SOUP_LOGGER (logger), msg);
break;
case SOUP_MESSAGE_IO_STATE_BODY:
diff --git a/tests/logger-test.c b/tests/logger-test.c
index b8d882ea..19145b21 100644
--- a/tests/logger-test.c
+++ b/tests/logger-test.c
@@ -4,11 +4,22 @@
#include "test-utils.h"
+static const char body_data[] =
+ "Lorem ipsum dolor sit amet, consectetur adipiscing elit, sed do "
+ "eiusmod tempor incididunt ut labore et dolore magna aliqua. Ut "
+ "im ad minim veniam, quis nostrud exercitation ullamco laboris "
+ "nisi ut aliquip ex ea commodo consequat. Duis aute irure dolor in "
+ "reprehenderit in voluptate velit esse cillum dolore eu fugiat nulla "
+ "pariatur. Excepteur sint occaecat cupidatat non proident, sunt in "
+ "culpa qui officia deserunt mollit anim id est laborum.";
+
GUri *base_uri;
typedef struct {
GHashTable *request;
GHashTable *response;
+ GByteArray *request_body;
+ GByteArray *response_body;
} LogData;
static void
@@ -16,6 +27,8 @@ log_data_clear (LogData *data)
{
g_clear_pointer (&data->request, g_hash_table_destroy);
g_clear_pointer (&data->response, g_hash_table_destroy);
+ g_clear_pointer (&data->request_body, g_byte_array_unref);
+ g_clear_pointer (&data->response_body, g_byte_array_unref);
}
static void
@@ -26,17 +39,29 @@ printer (SoupLogger *logger,
LogData *log)
{
GHashTable **table;
+ GByteArray **body;
- if (direction == '>')
+ if (direction == '>') {
table = &log->request;
- else if (direction == '<')
+ body = &log->request_body;
+ } else if (direction == '<') {
table = &log->response;
- else
+ body = &log->response_body;
+ } else
return;
if (!*table) {
+ /* first logger call; initialize headers */
*table = g_hash_table_new_full (g_str_hash, g_str_equal, g_free, g_free);
g_hash_table_insert (*table, g_strdup ("status-line"), g_strdup (data));
+ } else if (!*data) {
+ /* empty line with direction delimits body */
+ *body = g_byte_array_new ();
+ } else if (*body) {
+ /* we're only reading body now */
+ if (!strcmp (data, "[...]"))
+ return;
+ g_byte_array_append (*body, (const unsigned char *)data, strlen (data));
} else {
char *p;
@@ -51,7 +76,7 @@ do_logger_minimal_test (void)
SoupSession *session;
SoupLogger *logger;
SoupMessage *msg;
- LogData log = { NULL, NULL };
+ LogData log = { NULL, NULL, NULL, NULL };
session = soup_test_session_new (NULL);
@@ -78,6 +103,9 @@ do_logger_minimal_test (void)
g_assert_true (g_hash_table_contains (log.response, "Soup-Debug"));
g_assert_cmpstr (g_hash_table_lookup (log.response, "status-line"), ==, "HTTP/1.1 200 OK");
+ g_assert_null (log.request_body);
+ g_assert_null (log.response_body);
+
log_data_clear (&log);
soup_test_session_abort_unref (session);
@@ -90,7 +118,7 @@ do_logger_headers_test (void)
SoupLogger *logger;
SoupMessage *msg;
char *host;
- LogData log = { NULL, NULL };
+ LogData log = { NULL, NULL, NULL, NULL };
session = soup_test_session_new (NULL);
@@ -128,10 +156,120 @@ do_logger_headers_test (void)
g_assert_true (g_hash_table_contains (log.response, "Content-Length"));
g_assert_cmpstr (g_hash_table_lookup (log.response, "status-line"), ==, "HTTP/1.1 200 OK");
g_assert_cmpstr (g_hash_table_lookup (log.response, "Content-Type"), ==, "text/plain");
- g_assert_cmpstr (g_hash_table_lookup (log.response, "Content-Length"), ==, "5");
+ g_assert_cmpint (atoi (g_hash_table_lookup (log.response, "Content-Length")), ==, sizeof (body_data)
- 1);
+
+ g_assert_null (log.request_body);
+ g_assert_null (log.response_body);
+
+ log_data_clear (&log);
+
+ soup_test_session_abort_unref (session);
+}
+
+static void
+do_logger_body_test (void)
+{
+ GInputStream *body;
+ GBytes *request;
+ SoupSession *session;
+ SoupLogger *logger;
+ SoupMessage *msg;
+ char *host;
+ LogData log = { NULL, NULL, NULL, NULL };
+
+ session = soup_test_session_new (NULL);
+
+ logger = soup_logger_new (SOUP_LOGGER_LOG_BODY);
+ soup_logger_set_printer (logger, (SoupLoggerPrinter)printer, &log, NULL);
+ soup_session_add_feature (session, SOUP_SESSION_FEATURE (logger));
+
+ msg = soup_message_new_from_uri ("GET", base_uri);
+
+ request = g_bytes_new_static (body_data, sizeof (body_data) - 1);
+ soup_message_set_request_body_from_bytes (msg, NULL, request);
+ g_bytes_unref (request);
+
+ body = soup_session_send (session, msg, NULL, NULL);
+ g_assert_nonnull (body);
+
+ for (;;) {
+ gssize skip = g_input_stream_skip (body, 32, NULL, NULL);
+ if (skip <= 0)
+ break;
+ }
+
+ g_object_unref (body);
+ g_object_unref (msg);
+
+ g_assert_nonnull (log.request);
+ g_assert_cmpuint (g_hash_table_size (log.request), ==, 7);
+ g_assert_true (g_hash_table_contains (log.request, "status-line"));
+ g_assert_true (g_hash_table_contains (log.request, "Soup-Debug-Timestamp"));
+ g_assert_true (g_hash_table_contains (log.request, "Soup-Debug"));
+ g_assert_true (g_hash_table_contains (log.request, "Host"));
+ g_assert_true (g_hash_table_contains (log.request, "Accept-Encoding"));
+ g_assert_true (g_hash_table_contains (log.request, "Connection"));
+ g_assert_cmpstr (g_hash_table_lookup (log.request, "status-line"), ==, "GET / HTTP/1.1");
+ host = g_strdup_printf ("127.0.0.1:%d", g_uri_get_port (base_uri));
+ g_assert_cmpstr (g_hash_table_lookup (log.request, "Host"), ==, host);
+ g_free (host);
+ g_assert_cmpstr (g_hash_table_lookup (log.request, "Accept-Encoding"), ==, "gzip, deflate");
+ g_assert_cmpstr (g_hash_table_lookup (log.request, "Connection"), ==, "Keep-Alive");
+ g_assert_cmpint (atoi (g_hash_table_lookup (log.request, "Content-Length")), ==, sizeof (body_data)
- 1);
+
+ g_assert_nonnull (log.response);
+ g_assert_cmpuint (g_hash_table_size (log.response), ==, 6);
+ g_assert_true (g_hash_table_contains (log.response, "status-line"));
+ g_assert_true (g_hash_table_contains (log.response, "Soup-Debug-Timestamp"));
+ g_assert_true (g_hash_table_contains (log.response, "Soup-Debug"));
+ g_assert_true (g_hash_table_contains (log.response, "Date"));
+ g_assert_true (g_hash_table_contains (log.response, "Content-Type"));
+ g_assert_true (g_hash_table_contains (log.response, "Content-Length"));
+ g_assert_cmpstr (g_hash_table_lookup (log.response, "status-line"), ==, "HTTP/1.1 200 OK");
+ g_assert_cmpstr (g_hash_table_lookup (log.response, "Content-Type"), ==, "text/plain");
+ g_assert_cmpint (atoi (g_hash_table_lookup (log.response, "Content-Length")), ==, sizeof (body_data)
- 1);
+
+ g_assert_nonnull (log.request_body);
+ g_assert_nonnull (log.response_body);
+
+ g_assert_cmpmem (log.request_body->data,
+ log.request_body->len,
+ body_data, sizeof (body_data) - 1);
+
+ g_assert_cmpmem (log.response_body->data,
+ log.response_body->len,
+ body_data, sizeof (body_data) - 1);
log_data_clear (&log);
+ /* restrict maximum body size */
+ soup_logger_set_max_body_size (logger, 64);
+
+ msg = soup_message_new_from_uri ("GET", base_uri);
+ body = soup_session_send (session, msg, NULL, NULL);
+ g_assert_nonnull (body);
+
+ for (;;) {
+ gssize skip = g_input_stream_skip (body, 32, NULL, NULL);
+ if (skip <= 0)
+ break;
+ }
+
+ g_object_unref (body);
+ g_object_unref (msg);
+
+ g_assert_nonnull (log.request);
+ g_assert_null (log.request_body);
+ g_assert_nonnull (log.response);
+ g_assert_nonnull (log.response_body);
+
+ g_assert_cmpmem (log.response_body->data,
+ log.response_body->len,
+ body_data, 64);
+
+ log_data_clear (&log);
+
+ g_object_unref (logger);
soup_test_session_abort_unref (session);
}
@@ -146,14 +284,15 @@ filter (SoupLogger *logger,
static void
do_logger_filters_test (void)
{
+ GInputStream *body;
SoupSession *session;
SoupLogger *logger;
SoupMessage *msg;
- LogData log = { NULL, NULL };
+ LogData log = { NULL, NULL, NULL, NULL };
session = soup_test_session_new (NULL);
- logger = soup_logger_new (SOUP_LOGGER_LOG_HEADERS);
+ logger = soup_logger_new (SOUP_LOGGER_LOG_BODY);
soup_logger_set_printer (logger, (SoupLoggerPrinter)printer, &log, NULL);
soup_session_add_feature (session, SOUP_SESSION_FEATURE (logger));
@@ -168,6 +307,9 @@ do_logger_filters_test (void)
g_assert_nonnull (log.request);
g_assert_cmpuint (g_hash_table_size (log.request), ==, 3);
g_assert_null (log.response);
+ g_assert_null (log.request_body);
+ g_assert_null (log.response_body);
+
log_data_clear (&log);
/* Log request with headers level and response with minimal */
@@ -182,6 +324,9 @@ do_logger_filters_test (void)
g_assert_cmpuint (g_hash_table_size (log.request), ==, 6);
g_assert_nonnull (log.response);
g_assert_cmpuint (g_hash_table_size (log.response), ==, 3);
+ g_assert_null (log.request_body);
+ g_assert_null (log.response_body);
+
log_data_clear (&log);
/* Only log response with headers level */
@@ -195,6 +340,39 @@ do_logger_filters_test (void)
g_assert_null (log.request);
g_assert_nonnull (log.response);
g_assert_cmpuint (g_hash_table_size (log.response), ==, 6);
+ g_assert_null (log.request_body);
+ g_assert_null (log.response_body);
+
+ log_data_clear (&log);
+
+ /* Log request with minimal and response with body */
+ soup_logger_set_request_filter (logger, filter, GUINT_TO_POINTER (SOUP_LOGGER_LOG_MINIMAL), NULL);
+ soup_logger_set_response_filter (logger, filter, GUINT_TO_POINTER (SOUP_LOGGER_LOG_BODY), NULL);
+
+ msg = soup_message_new_from_uri ("GET", base_uri);
+ body = soup_session_send (session, msg, NULL, NULL);
+ g_assert_nonnull (body);
+
+ for (;;) {
+ gssize skip = g_input_stream_skip (body, 32, NULL, NULL);
+ if (skip <= 0)
+ break;
+ }
+
+ g_object_unref (body);
+ g_object_unref (msg);
+
+ g_assert_nonnull (log.request);
+ g_assert_null (log.request_body);
+ g_assert_cmpuint (g_hash_table_size (log.request), ==, 3);
+ g_assert_nonnull (log.response);
+ g_assert_cmpuint (g_hash_table_size (log.response), ==, 6);
+ g_assert_nonnull (log.response_body);
+
+ g_assert_cmpmem (log.response_body->data,
+ log.response_body->len,
+ body_data, sizeof (body_data) - 1);
+
log_data_clear (&log);
g_object_unref (logger);
@@ -208,7 +386,7 @@ do_logger_cookies_test (void)
SoupLogger *logger;
GUri *uri;
SoupMessage *msg;
- LogData log = { NULL, NULL };
+ LogData log = { NULL, NULL, NULL, NULL };
session = soup_test_session_new (NULL);
soup_session_add_feature_by_type (session, SOUP_TYPE_COOKIE_JAR);
@@ -260,7 +438,9 @@ server_callback (SoupServer *server,
}
soup_server_message_set_status (msg, SOUP_STATUS_OK, NULL);
soup_server_message_set_response (msg, "text/plain",
- SOUP_MEMORY_STATIC, "index", 5);
+ SOUP_MEMORY_STATIC,
+ body_data,
+ sizeof (body_data) - 1);
}
int
@@ -277,6 +457,7 @@ main (int argc, char **argv)
g_test_add_func ("/logger/minimal", do_logger_minimal_test);
g_test_add_func ("/logger/headers", do_logger_headers_test);
+ g_test_add_func ("/logger/body", do_logger_body_test);
g_test_add_func ("/logger/filters", do_logger_filters_test);
g_test_add_func ("/logger/cookies", do_logger_cookies_test);
diff --git a/tests/test-utils.c b/tests/test-utils.c
index 88247a98..21ece494 100644
--- a/tests/test-utils.c
+++ b/tests/test-utils.c
@@ -289,7 +289,7 @@ soup_test_session_new (const char *propname, ...)
}
if (http_debug_level && !logger) {
- SoupLoggerLogLevel level = MIN ((SoupLoggerLogLevel)http_debug_level,
SOUP_LOGGER_LOG_HEADERS);
+ SoupLoggerLogLevel level = MIN ((SoupLoggerLogLevel)http_debug_level, SOUP_LOGGER_LOG_BODY);
logger = soup_logger_new (level);
}
[
Date Prev][
Date Next] [
Thread Prev][
Thread Next]
[
Thread Index]
[
Date Index]
[
Author Index]
