Commit c61f62f9 authored by Daniel Kolesa's avatar Daniel Kolesa
Browse files

logger: re-add support for logging request/response bodies

parent 12cfc749
Pipeline #264059 passed with stages
in 1 minute and 55 seconds
......@@ -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
......
......@@ -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',
......
......@@ -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',
......
......@@ -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 (
......
/* 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;
}
/*
* 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
/*
* 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
......@@ -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,