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