libsoup/soup-logger.c

   1 /* -*- Mode: C; tab-width: 8; indent-tabs-mode: t; c-basic-offset: 8 -*- */
   2 /*
   3  * soup-logger.c
   4  *
   5  * Copyright (C) 2001-2004 Novell, Inc.
   6  * Copyright (C) 2008 Red Hat, Inc.
   7  * Copyright (C) 2013 Igalia, S.L.
   8  */
   9
  10 #ifdef HAVE_CONFIG_H
  11 #include <config.h>
  12 #endif
  13
  14 #include <stdio.h>
  15 #include <string.h>
  16
  17 #include "soup-logger.h"
  18 #include "soup.h"
  19
  20 /**
  21  * SECTION:soup-logger
  22  * @short_description: Debug logging support
  23  *
  24  * #SoupLogger watches a #SoupSession and logs the HTTP traffic that
  25  * it generates, for debugging purposes. Many applications use an
  26  * environment variable to determine whether or not to use
  27  * #SoupLogger, and to determine the amount of debugging output.
  28  *
  29  * To use #SoupLogger, first create a logger with soup_logger_new(),
  30  * optionally configure it with soup_logger_set_request_filter(),
  31  * soup_logger_set_response_filter(), and soup_logger_set_printer(),
  32  * and then attach it to a session (or multiple sessions) with
  33  * soup_session_add_feature().
  34  *
  35  * By default, the debugging output is sent to
  36  * <literal>stdout</literal>, and looks something like:
  37  *
  38  * <informalexample><screen>
  39  * > POST /unauth HTTP/1.1
  40  * > Soup-Debug-Timestamp: 1200171744
  41  * > Soup-Debug: SoupSessionAsync 1 (0x612190), SoupMessage 1 (0x617000), SoupSocket 1 (0x612220)
  42  * > Host: localhost
  43  * > Content-Type: text/plain
  44  * > Connection: close
  45  * >
  46  * > This is a test.
  47  *
  48  * &lt; HTTP/1.1 201 Created
  49  * &lt; Soup-Debug-Timestamp: 1200171744
  50  * &lt; Soup-Debug: SoupMessage 1 (0x617000)
  51  * &lt; Date: Sun, 12 Jan 2008 21:02:24 GMT
  52  * &lt; Content-Length: 0
  53  * </screen></informalexample>
  54  *
  55  * The <literal>Soup-Debug-Timestamp</literal> line gives the time (as
  56  * a <type>time_t</type>) when the request was sent, or the response fully
  57  * received.
  58  *
  59  * The <literal>Soup-Debug</literal> line gives further debugging
  60  * information about the #SoupSession, #SoupMessage, and #SoupSocket
  61  * involved; the hex numbers are the addresses of the objects in
  62  * question (which may be useful if you are running in a debugger).
  63  * The decimal IDs are simply counters that uniquely identify objects
  64  * across the lifetime of the #SoupLogger. In particular, this can be
  65  * used to identify when multiple messages are sent across the same
  66  * connection.
  67  *
  68  * Currently, the request half of the message is logged just before
  69  * the first byte of the request gets written to the network (from the
  70  * #SoupSession::request_started signal), which means that if you have
  71  * not made the complete request body available at that point, it will
  72  * not be logged.
  73  *
  74  * The response is logged just after the last byte of the response
  75  * body is read from the network (from the #SoupMessage::got_body or
  76  * #SoupMessage::got_informational signal), which means that the
  77  * #SoupMessage::got_headers signal, and anything triggered off it
  78  * (such as #SoupSession::authenticate) will be emitted
  79  * <emphasis>before</emphasis> the response headers are actually
  80  * logged.
  81  *
  82  * If the response doesn't happen to trigger the
  83  * #SoupMessage::got_body nor #SoupMessage::got_informational signals
  84  * due to, for example, a cancellation before receiving the last byte
  85  * of the response body, the response will still be logged on the
  86  * event of the #SoupMessage::finished signal.
  87  **/
  88
  89 static void soup_logger_session_feature_init (SoupSessionFeatureInterface *feature_interface, gpointer interface_data);
  90
  91 G_DEFINE_TYPE_WITH_CODE (SoupLogger, soup_logger, G_TYPE_OBJECT,
  92                          G_IMPLEMENT_INTERFACE (SOUP_TYPE_SESSION_FEATURE,
  93                                                 soup_logger_session_feature_init))
  94
  95 typedef struct {
  96         /* We use a mutex so that if requests are being run in
  97          * multiple threads, we don't mix up the output.
  98          */
  99         GMutex             lock;
 100
 101         GQuark              tag;
 102         GHashTable         *ids;
 103
 104         SoupLoggerLogLevel  level;
 105         int                 max_body_size;
 106
 107         SoupLoggerFilter    request_filter;
 108         gpointer            request_filter_data;
 109         GDestroyNotify      request_filter_dnotify;
 110
 111         SoupLoggerFilter    response_filter;
 112         gpointer            response_filter_data;
 113         GDestroyNotify      response_filter_dnotify;
 114
 115         SoupLoggerPrinter   printer;
 116         gpointer            printer_data;
 117         GDestroyNotify      printer_dnotify;
 118 } SoupLoggerPrivate;
 119 #define SOUP_LOGGER_GET_PRIVATE(o) (G_TYPE_INSTANCE_GET_PRIVATE ((o), SOUP_TYPE_LOGGER, SoupLoggerPrivate))
 120
 121 static void
 122 soup_logger_init (SoupLogger *logger)
 123 {
 124         SoupLoggerPrivate *priv = SOUP_LOGGER_GET_PRIVATE (logger);
 125
 126         g_mutex_init (&priv->lock);
 127         priv->tag = g_quark_from_static_string (g_strdup_printf ("SoupLogger-%p", logger));
 128         priv->ids = g_hash_table_new (NULL, NULL);
 129 }
 130
 131 static void
 132 soup_logger_finalize (GObject *object)
 133 {
 134         SoupLoggerPrivate *priv = SOUP_LOGGER_GET_PRIVATE (object);
 135
 136         g_hash_table_destroy (priv->ids);
 137
 138         if (priv->request_filter_dnotify)
 139                 priv->request_filter_dnotify (priv->request_filter_data);
 140         if (priv->response_filter_dnotify)
 141                 priv->response_filter_dnotify (priv->response_filter_data);
 142         if (priv->printer_dnotify)
 143                 priv->printer_dnotify (priv->printer_data);
 144
 145         g_mutex_clear (&priv->lock);
 146
 147         G_OBJECT_CLASS (soup_logger_parent_class)->finalize (object);
 148 }
 149
 150 static void
 151 soup_logger_class_init (SoupLoggerClass *logger_class)
 152 {
 153         GObjectClass *object_class = G_OBJECT_CLASS (logger_class);
 154
 155         g_type_class_add_private (logger_class, sizeof (SoupLoggerPrivate));
 156
 157         object_class->finalize = soup_logger_finalize;
 158 }
 159
 160 /**
 161  * SoupLoggerLogLevel:
 162  * @SOUP_LOGGER_LOG_NONE: No logging
 163  * @SOUP_LOGGER_LOG_MINIMAL: Log the Request-Line or Status-Line and
 164  * the Soup-Debug pseudo-headers
 165  * @SOUP_LOGGER_LOG_HEADERS: Log the full request/response headers
 166  * @SOUP_LOGGER_LOG_BODY: Log the full headers and request/response
 167  * bodies.
 168  *
 169  * Describes the level of logging output to provide.
 170  **/
 171
 172 /**
 173  * soup_logger_new:
 174  * @level: the debug level
 175  * @max_body_size: the maximum body size to output, or -1
 176  *
 177  * Creates a new #SoupLogger with the given debug level. If @level is
 178  * %SOUP_LOGGER_LOG_BODY, @max_body_size gives the maximum number of
 179  * bytes of the body that will be logged. (-1 means "no limit".)
 180  *
 181  * If you need finer control over what message parts are and aren't
 182  * logged, use soup_logger_set_request_filter() and
 183  * soup_logger_set_response_filter().
 184  *
 185  * Returns: a new #SoupLogger
 186  **/
 187 SoupLogger *
 188 soup_logger_new (SoupLoggerLogLevel level, int max_body_size)
 189 {
 190         SoupLogger *logger;
 191         SoupLoggerPrivate *priv;
 192
 193         logger = g_object_new (SOUP_TYPE_LOGGER, NULL);
 194
 195         priv = SOUP_LOGGER_GET_PRIVATE (logger);
 196         priv->level = level;
 197         priv->max_body_size = max_body_size;
 198
 199         return logger;
 200 }
 201
 202 /**
 203  * SoupLoggerFilter:
 204  * @logger: the #SoupLogger
 205  * @msg: the message being logged
 206  * @user_data: the data passed to soup_logger_set_request_filter()
 207  * or soup_logger_set_response_filter()
 208  *
 209  * The prototype for a logging filter. The filter callback will be
 210  * invoked for each request or response, and should analyze it and
 211  * return a #SoupLoggerLogLevel value indicating how much of the
 212  * message to log. Eg, it might choose between %SOUP_LOGGER_LOG_BODY
 213  * and %SOUP_LOGGER_LOG_HEADERS depending on the Content-Type.
 214  *
 215  * Return value: a #SoupLoggerLogLevel value indicating how much of
 216  * the message to log
 217  **/
 218
 219 /**
 220  * soup_logger_set_request_filter:
 221  * @logger: a #SoupLogger
 222  * @request_filter: the callback for request debugging
 223  * @filter_data: data to pass to the callback
 224  * @destroy: a #GDestroyNotify to free @filter_data
 225  *
 226  * Sets up a filter to determine the log level for a given request.
 227  * For each HTTP request @logger will invoke @request_filter to
 228  * determine how much (if any) of that request to log. (If you do not
 229  * set a request filter, @logger will just always log requests at the
 230  * level passed to soup_logger_new().)
 231  **/
 232 void
 233 soup_logger_set_request_filter (SoupLogger       *logger,
 234                                 SoupLoggerFilter  request_filter,
 235                                 gpointer          filter_data,
 236                                 GDestroyNotify    destroy)
 237 {
 238         SoupLoggerPrivate *priv = SOUP_LOGGER_GET_PRIVATE (logger);
 239
 240         priv->request_filter         = request_filter;
 241         priv->request_filter_data    = filter_data;
 242         priv->request_filter_dnotify = destroy;
 243 }
 244
 245 /**
 246  * soup_logger_set_response_filter:
 247  * @logger: a #SoupLogger
 248  * @response_filter: the callback for response debugging
 249  * @filter_data: data to pass to the callback
 250  * @destroy: a #GDestroyNotify to free @filter_data
 251  *
 252  * Sets up a filter to determine the log level for a given response.
 253  * For each HTTP response @logger will invoke @response_filter to
 254  * determine how much (if any) of that response to log. (If you do not
 255  * set a response filter, @logger will just always log responses at
 256  * the level passed to soup_logger_new().)
 257  **/
 258 void
 259 soup_logger_set_response_filter (SoupLogger       *logger,
 260                                  SoupLoggerFilter  response_filter,
 261                                  gpointer          filter_data,
 262                                  GDestroyNotify    destroy)
 263 {
 264         SoupLoggerPrivate *priv = SOUP_LOGGER_GET_PRIVATE (logger);
 265
 266         priv->response_filter         = response_filter;
 267         priv->response_filter_data    = filter_data;
 268         priv->response_filter_dnotify = destroy;
 269 }
 270
 271 /**
 272  * SoupLoggerPrinter:
 273  * @logger: the #SoupLogger
 274  * @level: the level of the information being printed.
 275  * @direction: a single-character prefix to @data
 276  * @data: data to print
 277  * @user_data: the data passed to soup_logger_set_printer()
 278  *
 279  * The prototype for a custom printing callback.
 280  *
 281  * @level indicates what kind of information is being printed. Eg, it
 282  * will be %SOUP_LOGGER_LOG_HEADERS if @data is header data.
 283  *
 284  * @direction is either '<', '>', or ' ', and @data is the single line
 285  * to print; the printer is expected to add a terminating newline.
 286  *
 287  * To get the effect of the default printer, you would do:
 288  *
 289  * <informalexample><programlisting>
 290  *      printf ("%c %s\n", direction, data);
 291  * </programlisting></informalexample>
 292  **/
 293
 294 /**
 295  * soup_logger_set_printer:
 296  * @logger: a #SoupLogger
 297  * @printer: the callback for printing logging output
 298  * @printer_data: data to pass to the callback
 299  * @destroy: a #GDestroyNotify to free @printer_data
 300  *
 301  * Sets up an alternate log printing routine, if you don't want
 302  * the log to go to <literal>stdout</literal>.
 303  **/
 304 void
 305 soup_logger_set_printer (SoupLogger        *logger,
 306                          SoupLoggerPrinter  printer,
 307                          gpointer           printer_data,
 308                          GDestroyNotify     destroy)
 309 {
 310         SoupLoggerPrivate *priv = SOUP_LOGGER_GET_PRIVATE (logger);
 311
 312         priv->printer         = printer;
 313         priv->printer_data    = printer_data;
 314         priv->printer_dnotify = destroy;
 315 }
 316
 317 static guint
 318 soup_logger_get_id (SoupLogger *logger, gpointer object)
 319 {
 320         SoupLoggerPrivate *priv = SOUP_LOGGER_GET_PRIVATE (logger);
 321
 322         return GPOINTER_TO_UINT (g_object_get_qdata (object, priv->tag));
 323 }
 324
 325 static guint
 326 soup_logger_set_id (SoupLogger *logger, gpointer object)
 327 {
 328         SoupLoggerPrivate *priv = SOUP_LOGGER_GET_PRIVATE (logger);
 329         gpointer klass = G_OBJECT_GET_CLASS (object);
 330         gpointer id;
 331
 332         id = g_hash_table_lookup (priv->ids, klass);
 333         id = (char *)id + 1;
 334         g_hash_table_insert (priv->ids, klass, id);
 335
 336         g_object_set_qdata (object, priv->tag, id);
 337         return GPOINTER_TO_UINT (id);
 338 }
 339
 340 /**
 341  * soup_logger_attach:
 342  * @logger: a #SoupLogger
 343  * @session: a #SoupSession
 344  *
 345  * Sets @logger to watch @session and print debug information for
 346  * its messages.
 347  *
 348  * (The session will take a reference on @logger, which will be
 349  * removed when you call soup_logger_detach(), or when the session is
 350  * destroyed.)
 351  *
 352  * Deprecated: Use soup_session_add_feature() instead.
 353  **/
 354 void
 355 soup_logger_attach (SoupLogger  *logger,
 356                     SoupSession *session)
 357 {
 358         soup_session_add_feature (session, SOUP_SESSION_FEATURE (logger));
 359 }
 360
 361 /**
 362  * soup_logger_detach:
 363  * @logger: a #SoupLogger
 364  * @session: a #SoupSession
 365  *
 366  * Stops @logger from watching @session.
 367  *
 368  * Deprecated: Use soup_session_remove_feature() instead.
 369  **/
 370 void
 371 soup_logger_detach (SoupLogger  *logger,
 372                     SoupSession *session)
 373 {
 374         soup_session_remove_feature (session, SOUP_SESSION_FEATURE (logger));
 375 }
 376
 377 static void soup_logger_print (SoupLogger *logger, SoupLoggerLogLevel level,
 378                                char direction, const char *format, ...) G_GNUC_PRINTF (4, 5);
 379
 380 static void
 381 soup_logger_print (SoupLogger *logger, SoupLoggerLogLevel level,
 382                    char direction, const char *format, ...)
 383 {
 384         SoupLoggerPrivate *priv = SOUP_LOGGER_GET_PRIVATE (logger);
 385         va_list args;
 386         char *data, *line, *end;
 387
 388         va_start (args, format);
 389         data = g_strdup_vprintf (format, args);
 390         va_end (args);
 391
 392         if (level == SOUP_LOGGER_LOG_BODY && priv->max_body_size > 0) {
 393                 if (strlen (data) > priv->max_body_size + 6)
 394                         strcpy (data + priv->max_body_size, "\n[...]");
 395         }
 396
 397         line = data;
 398         do {
 399                 end = strchr (line, '\n');
 400                 if (end)
 401                         *end = '\0';
 402                 if (priv->printer) {
 403                         priv->printer (logger, level, direction,
 404                                        line, priv->printer_data);
 405                 } else
 406                         printf ("%c %s\n", direction, line);
 407
 408                 line = end + 1;
 409         } while (end && *line);
 410
 411         g_free (data);
 412 }
 413
 414 static void
 415 soup_logger_print_basic_auth (SoupLogger *logger, const char *value)
 416 {
 417         char *decoded, *decoded_utf8, *p;
 418         gsize len;
 419
 420         decoded = (char *)g_base64_decode (value + 6, &len);
 421         if (decoded && !g_utf8_validate (decoded, -1, NULL)) {
 422                 decoded_utf8 = g_convert_with_fallback (decoded, -1,
 423                                                         "UTF-8", "ISO-8859-1",
 424                                                         NULL, NULL, &len,
 425                                                         NULL);
 426                 if (decoded_utf8) {
 427                         g_free (decoded);
 428                         decoded = decoded_utf8;
 429                 }
 430         }
 431
 432         if (!decoded)
 433                 decoded = g_strdup (value);
 434         p = strchr (decoded, ':');
 435         if (p) {
 436                 while (++p < decoded + len)
 437                         *p = '*';
 438         }
 439         soup_logger_print (logger, SOUP_LOGGER_LOG_HEADERS, '>',
 440                            "Authorization: Basic [%.*s]", (int)len, decoded);
 441         g_free (decoded);
 442 }
 443
 444 static void
 445 print_request (SoupLogger *logger, SoupMessage *msg,
 446                SoupSession *session, SoupSocket *socket,
 447                gboolean restarted)
 448 {
 449         SoupLoggerPrivate *priv = SOUP_LOGGER_GET_PRIVATE (logger);
 450         SoupLoggerLogLevel log_level;
 451         SoupMessageHeadersIter iter;
 452         const char *name, *value;
 453         SoupURI *uri;
 454
 455         if (priv->request_filter) {
 456                 log_level = priv->request_filter (logger, msg,
 457                                                   priv->request_filter_data);
 458         } else
 459                 log_level = priv->level;
 460
 461         if (log_level == SOUP_LOGGER_LOG_NONE)
 462                 return;
 463
 464         uri = soup_message_get_uri (msg);
 465         if (msg->method == SOUP_METHOD_CONNECT) {
 466                 soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, '>',
 467                                    "CONNECT %s:%u HTTP/1.%d",
 468                                    uri->host, uri->port,
 469                                    soup_message_get_http_version (msg));
 470         } else {
 471                 soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, '>',
 472                                    "%s %s%s%s HTTP/1.%d",
 473                                    msg->method, uri->path,
 474                                    uri->query ? "?" : "",
 475                                    uri->query ? uri->query : "",
 476                                    soup_message_get_http_version (msg));
 477         }
 478
 479         soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, '>',
 480                            "Soup-Debug-Timestamp: %lu",
 481                            (unsigned long)time (0));
 482         soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, '>',
 483                            "Soup-Debug: %s %u (%p), %s %u (%p), %s %u (%p)%s",
 484                            g_type_name_from_instance ((GTypeInstance *)session),
 485                            soup_logger_get_id (logger, session), session,
 486                            g_type_name_from_instance ((GTypeInstance *)msg),
 487                            soup_logger_get_id (logger, msg), msg,
 488                            g_type_name_from_instance ((GTypeInstance *)socket),
 489                            soup_logger_get_id (logger, socket), socket,
 490                            restarted ? ", restarted" : "");
 491
 492         if (log_level == SOUP_LOGGER_LOG_MINIMAL)
 493                 return;
 494
 495         if (!soup_message_headers_get_one (msg->request_headers, "Host")) {
 496                 char *uri_host;
 497
 498                 if (strchr (uri->host, ':'))
 499                         uri_host = g_strdup_printf ("[%s]", uri->host);
 500                 else if (g_hostname_is_non_ascii (uri->host))
 501                         uri_host = g_hostname_to_ascii (uri->host);
 502                 else
 503                         uri_host = uri->host;
 504
 505                 soup_logger_print (logger, SOUP_LOGGER_LOG_HEADERS, '>',
 506                                    "Host: %s%c%u", uri_host,
 507                                    soup_uri_uses_default_port (uri) ? '\0' : ':',
 508                                    uri->port);
 509
 510                 if (uri_host != uri->host)
 511                         g_free (uri_host);
 512         }
 513         soup_message_headers_iter_init (&iter, msg->request_headers);
 514         while (soup_message_headers_iter_next (&iter, &name, &value)) {
 515                 if (!g_ascii_strcasecmp (name, "Authorization") &&
 516                     !g_ascii_strncasecmp (value, "Basic ", 6))
 517                         soup_logger_print_basic_auth (logger, value);
 518                 else {
 519                         soup_logger_print (logger, SOUP_LOGGER_LOG_HEADERS, '>',
 520                                            "%s: %s", name, value);
 521                 }
 522         }
 523         if (log_level == SOUP_LOGGER_LOG_HEADERS)
 524                 return;
 525
 526         if (msg->request_body->length &&
 527             soup_message_body_get_accumulate (msg->request_body)) {
 528                 SoupBuffer *request;
 529
 530                 request = soup_message_body_flatten (msg->request_body);
 531                 g_return_if_fail (request != NULL);
 532                 soup_buffer_free (request);
 533
 534                 if (soup_message_headers_get_expectations (msg->request_headers) != SOUP_EXPECTATION_CONTINUE) {
 535                         soup_logger_print (logger, SOUP_LOGGER_LOG_BODY, '>',
 536                                            "\n%s", msg->request_body->data);
 537                 }
 538         }
 539 }
 540
 541 static void
 542 print_response (SoupLogger *logger, SoupMessage *msg)
 543 {
 544         SoupLoggerPrivate *priv = SOUP_LOGGER_GET_PRIVATE (logger);
 545         SoupLoggerLogLevel log_level;
 546         SoupMessageHeadersIter iter;
 547         const char *name, *value;
 548
 549         if (priv->response_filter) {
 550                 log_level = priv->response_filter (logger, msg,
 551                                                    priv->response_filter_data);
 552         } else
 553                 log_level = priv->level;
 554
 555         if (log_level == SOUP_LOGGER_LOG_NONE)
 556                 return;
 557
 558         soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, '<',
 559                            "HTTP/1.%d %u %s\n",
 560                            soup_message_get_http_version (msg),
 561                            msg->status_code, msg->reason_phrase);
 562
 563         soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, '<',
 564                            "Soup-Debug-Timestamp: %lu",
 565                            (unsigned long)time (0));
 566         soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, '<',
 567                            "Soup-Debug: %s %u (%p)",
 568                            g_type_name_from_instance ((GTypeInstance *)msg),
 569                            soup_logger_get_id (logger, msg), msg);
 570
 571         if (log_level == SOUP_LOGGER_LOG_MINIMAL)
 572                 return;
 573
 574         soup_message_headers_iter_init (&iter, msg->response_headers);
 575         while (soup_message_headers_iter_next (&iter, &name, &value)) {
 576                 soup_logger_print (logger, SOUP_LOGGER_LOG_HEADERS, '<',
 577                                    "%s: %s", name, value);
 578         }
 579         if (log_level == SOUP_LOGGER_LOG_HEADERS)
 580                 return;
 581
 582         if (msg->response_body->data) {
 583                 soup_logger_print (logger, SOUP_LOGGER_LOG_BODY, '<',
 584                                    "\n%s", msg->response_body->data);
 585         }
 586 }
 587
 588 static void
 589 finished (SoupMessage *msg, gpointer user_data)
 590 {
 591         SoupLogger *logger = user_data;
 592         SoupLoggerPrivate *priv = SOUP_LOGGER_GET_PRIVATE (logger);
 593
 594         g_mutex_lock (&priv->lock);
 595
 596         print_response (logger, msg);
 597         soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, ' ', "");
 598
 599         g_mutex_unlock (&priv->lock);
 600 }
 601
 602 static void
 603 got_informational (SoupMessage *msg, gpointer user_data)
 604 {
 605         SoupLogger *logger = user_data;
 606         SoupLoggerPrivate *priv = SOUP_LOGGER_GET_PRIVATE (logger);
 607
 608         g_mutex_lock (&priv->lock);
 609
 610         g_signal_handlers_disconnect_by_func (msg, finished, logger);
 611         print_response (logger, msg);
 612         soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, ' ', "");
 613
 614         if (msg->status_code == SOUP_STATUS_CONTINUE && msg->request_body->data) {
 615                 SoupLoggerLogLevel log_level;
 616
 617                 soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, '>',
 618                                    "[Now sending request body...]");
 619
 620                 if (priv->request_filter) {
 621                         log_level = priv->request_filter (logger, msg,
 622                                                           priv->request_filter_data);
 623                 } else
 624                         log_level = priv->level;
 625
 626                 if (log_level == SOUP_LOGGER_LOG_BODY) {
 627                         soup_logger_print (logger, SOUP_LOGGER_LOG_BODY, '>',
 628                                            "%s", msg->request_body->data);
 629                 }
 630
 631                 soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, ' ', "");
 632         }
 633
 634         g_mutex_unlock (&priv->lock);
 635 }
 636
 637 static void
 638 got_body (SoupMessage *msg, gpointer user_data)
 639 {
 640         SoupLogger *logger = user_data;
 641         SoupLoggerPrivate *priv = SOUP_LOGGER_GET_PRIVATE (logger);
 642
 643         g_mutex_lock (&priv->lock);
 644
 645         g_signal_handlers_disconnect_by_func (msg, finished, logger);
 646         print_response (logger, msg);
 647         soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, ' ', "");
 648
 649         g_mutex_unlock (&priv->lock);
 650 }
 651
 652 static void
 653 soup_logger_request_queued (SoupSessionFeature *logger,
 654                             SoupSession *session,
 655                             SoupMessage *msg)
 656 {
 657         g_return_if_fail (SOUP_IS_MESSAGE (msg));
 658
 659         g_signal_connect (msg, "got-informational",
 660                           G_CALLBACK (got_informational),
 661                           logger);
 662         g_signal_connect (msg, "got-body",
 663                           G_CALLBACK (got_body),
 664                           logger);
 665         g_signal_connect (msg, "finished",
 666                           G_CALLBACK (finished),
 667                           logger);
 668 }
 669
 670 static void
 671 soup_logger_request_started (SoupSessionFeature *feature,
 672                              SoupSession *session,
 673                              SoupMessage *msg,
 674                              SoupSocket *socket)
 675 {
 676         SoupLogger *logger = SOUP_LOGGER (feature);
 677         gboolean restarted;
 678         guint msg_id;
 679
 680         g_return_if_fail (SOUP_IS_SESSION (session));
 681         g_return_if_fail (SOUP_IS_MESSAGE (msg));
 682         g_return_if_fail (SOUP_IS_SOCKET (socket));
 683
 684         msg_id = soup_logger_get_id (logger, msg);
 685         if (msg_id)
 686                 restarted = TRUE;
 687         else {
 688                 soup_logger_set_id (logger, msg);
 689                 restarted = FALSE;
 690         }
 691
 692         if (!soup_logger_get_id (logger, session))
 693                 soup_logger_set_id (logger, session);
 694
 695         if (!soup_logger_get_id (logger, socket))
 696                 soup_logger_set_id (logger, socket);
 697
 698         print_request (logger, msg, session, socket, restarted);
 699         soup_logger_print (logger, SOUP_LOGGER_LOG_MINIMAL, ' ', "");
 700 }
 701
 702 static void
 703 soup_logger_request_unqueued (SoupSessionFeature *logger,
 704                               SoupSession *session,
 705                               SoupMessage *msg)
 706 {
 707         g_return_if_fail (SOUP_IS_MESSAGE (msg));
 708
 709         g_signal_handlers_disconnect_by_func (msg, got_informational, logger);
 710         g_signal_handlers_disconnect_by_func (msg, got_body, logger);
 711         g_signal_handlers_disconnect_by_func (msg, finished, logger);
 712 }
 713
 714 static void
 715 soup_logger_session_feature_init (SoupSessionFeatureInterface *feature_interface,
 716                                   gpointer interface_data)
 717 {
 718         feature_interface->request_queued = soup_logger_request_queued;
 719         feature_interface->request_started = soup_logger_request_started;
 720         feature_interface->request_unqueued = soup_logger_request_unqueued;
 721 }