fetcher: Log failures into journal

Particularly when HTTP requests fail, I really want a lot more information.
We could theoretically stuff it into the `GError` message field, but
that gets ugly *fast*.

Using the systemd journal allows us to log things in a structured fashion.
Right now e.g. rpm-ostree won't be aware of this additional information,
but I think we could teach it to be down the line.

In the short term, users can learn to find it from `systemctl status rpm-ostreed`
or `journalctl -b -r -u rpm-ostreed`, etc.

One thing I'd like to do next is log successful fetches of e.g. commit objects
as well with more information about the originating server (things like the
final URL if we were redirected, did we use TLS pinning, what was the negotiated
TLS version+cipher, etc).

Closes: #708
Approved by: jlebon

src/libostree/ostree-fetcher-curl.c

@@ -37,6 +37,7 @@
 #endif
 
 #include "ostree-fetcher.h"
+#include "ostree-fetcher-util.h"
 #include "ostree-enumtypes.h"
 #include "ostree-repo-private.h"
 #include "otutil.h"
@@ -59,6 +60,7 @@ struct OstreeFetcher
   GObject parent_instance;
 
   OstreeFetcherConfigFlags config_flags;
+  char *remote_name;
   char *tls_ca_db_path;
   char *tls_client_cert_path;
   char *tls_client_key_path;
@@ -159,6 +161,7 @@ _ostree_fetcher_finalize (GObject *object)
 {
   OstreeFetcher *self = OSTREE_FETCHER (object);
 
+  g_free (self->remote_name);
   g_free (self->cookie_jar_path);
   g_free (self->proxy);
   g_assert_cmpint (g_hash_table_size (self->outstanding_requests), ==, 0);
@@ -222,9 +225,11 @@ _ostree_fetcher_init (OstreeFetcher *self)
 
 OstreeFetcher *
 _ostree_fetcher_new (int                      tmpdir_dfd,
+                     const char              *remote_name,
                      OstreeFetcherConfigFlags flags)
 {
   OstreeFetcher *fetcher = g_object_new (OSTREE_TYPE_FETCHER, "config-flags", flags, NULL);
+  fetcher->remote_name = g_strdup (remote_name);
   fetcher->tmpdir_dfd = tmpdir_dfd;
   return fetcher;
 }
@@ -303,9 +308,14 @@ check_multi_info (OstreeFetcher *fetcher)
                                          curl_easy_strerror (curlres));
             }
           else
+            {
               g_task_return_new_error (task, G_IO_ERROR, G_IO_ERROR_FAILED, "[%u] %s",
                                        curlres,
                                        curl_easy_strerror (curlres));
+              if (req->fetcher->remote_name)
+                _ostree_fetcher_journal_failure (req->fetcher->remote_name,
+                                                 eff_url, curl_easy_strerror (curlres));
+            }
         }
       else
         {
@@ -328,8 +338,13 @@ check_multi_info (OstreeFetcher *fetcher)
 
               if (req->idx + 1 == req->mirrorlist->len)
                 {
+                  g_autofree char *msg = g_strdup_printf ("Server returned HTTP %lu", response);
                   g_task_return_new_error (task, G_IO_ERROR, giocode,
-                                           "Server returned HTTP %lu", response);
+                                           "%s", msg);
+                  if (req->fetcher->remote_name)
+                    _ostree_fetcher_journal_failure (req->fetcher->remote_name,
+                                                     eff_url, msg);
+
                 }
               else
                 {

src/libostree/ostree-fetcher-soup.c

@@ -32,6 +32,7 @@
 
 #include "libglnx.h"
 #include "ostree-fetcher.h"
+#include "ostree-fetcher-util.h"
 #ifdef HAVE_LIBSOUP_CLIENT_CERTS
 #include "ostree-tls-cert-interaction.h"
 #endif
@@ -55,6 +56,7 @@ typedef struct {
   GError *initialization_error; /* Any failure to load the db */
 
   int tmpdir_dfd;
+  char *remote_name;
   char *tmpdir_name;
   GLnxLockFile tmpdir_lock;
   int base_tmpdir_dfd;
@@ -168,6 +170,8 @@ thread_closure_unref (ThreadClosure *thread_closure)
 
       g_clear_pointer (&thread_closure->oob_error, g_error_free);
 
+      g_free (thread_closure->remote_name);
+
       g_slice_free (ThreadClosure, thread_closure);
     }
 }
@@ -725,12 +729,13 @@ _ostree_fetcher_init (OstreeFetcher *self)
 
 OstreeFetcher *
 _ostree_fetcher_new (int                      tmpdir_dfd,
+                     const char              *remote_name,
                      OstreeFetcherConfigFlags flags)
 {
   OstreeFetcher *self;
 
   self = g_object_new (OSTREE_TYPE_FETCHER, "config-flags", flags, NULL);
-
+  self->thread_closure->remote_name = g_strdup (remote_name);
   self->thread_closure->base_tmpdir_dfd = tmpdir_dfd;
 
   return self;
@@ -1081,6 +1086,9 @@ on_request_sent (GObject        *object,
             }
           else
             {
+              g_autofree char *uristring
+                = soup_uri_to_string (soup_request_get_uri (pending->request), FALSE);
+
               GIOErrorEnum code;
               switch (msg->status_code)
                 {
@@ -1115,6 +1123,10 @@ on_request_sent (GObject        *object,
                 g_prefix_error (&local_error,
                                 "All %u mirrors failed. Last error was: ",
                                 pending->mirrorlist->len);
+              if (pending->thread_closure->remote_name)
+                _ostree_fetcher_journal_failure (pending->thread_closure->remote_name,
+                                                 uristring, local_error->message);
+
             }
           goto out;
         }

src/libostree/ostree-fetcher-util.c

@@ -23,6 +23,10 @@
 #include <gio/gfiledescriptorbased.h>
 #include <gio/gunixoutputstream.h>
 
+#ifdef HAVE_LIBSYSTEMD
+#include <systemd/sd-journal.h>
+#endif
+
 #include "ostree-fetcher-util.h"
 #include "otutil.h"
 
@@ -122,3 +126,23 @@ _ostree_fetcher_request_uri_to_membuf (OstreeFetcher  *fetcher,
                                                      out_contents, max_size,
                                                      cancellable, error);
 }
+
+#define OSTREE_HTTP_FAILURE_ID SD_ID128_MAKE(f0,2b,ce,89,a5,4e,4e,fa,b3,a9,4a,79,7d,26,20,4a)
+
+void
+_ostree_fetcher_journal_failure (const char *remote_name,
+                                 const char *url,
+                                 const char *msg)
+{
+#ifdef HAVE_LIBSYSTEMD
+  /* Sanity - we don't want to log this when doing local/file pulls */
+  if (!remote_name)
+    return;
+  sd_journal_send ("MESSAGE=libostree HTTP error from remote %s for <%s>: %s",
+                   remote_name, url, msg,
+                   "MESSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(OSTREE_HTTP_FAILURE_ID),
+                   "OSTREE_REMOTE=%s", remote_name,
+                   "OSTREE_URL=%s", url,
+                   NULL);
+#endif
+}

src/libostree/ostree-fetcher-util.h

@@ -44,6 +44,12 @@ gboolean _ostree_fetcher_request_uri_to_membuf (OstreeFetcher *fetcher,
                                                 guint64        max_size,
                                                 GCancellable   *cancellable,
                                                 GError         **error);
+
+void _ostree_fetcher_journal_failure (const char *remote_name,
+                                      const char *url,
+                                      const char *msg);
+
+
 G_END_DECLS
 
 #endif

src/libostree/ostree-fetcher.h

@@ -82,6 +82,7 @@ _ostree_fetcher_uri_to_string (OstreeFetcherURI *uri);
 GType   _ostree_fetcher_get_type (void) G_GNUC_CONST;
 
 OstreeFetcher *_ostree_fetcher_new (int                      tmpdir_dfd,
+                                    const char              *remote_name,
                                     OstreeFetcherConfigFlags flags);
 
 int  _ostree_fetcher_get_dfd (OstreeFetcher *fetcher);

src/libostree/ostree-repo-pull.c

@@ -2107,7 +2107,7 @@ _ostree_repo_remote_new_fetcher (OstreeRepo  *self,
   if (tls_permissive)
     fetcher_flags |= OSTREE_FETCHER_FLAGS_TLS_PERMISSIVE;
 
-  fetcher = _ostree_fetcher_new (self->tmp_dir_fd, fetcher_flags);
+  fetcher = _ostree_fetcher_new (self->tmp_dir_fd, remote_name, fetcher_flags);
 
   {
     g_autofree char *tls_client_cert_path = NULL;