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

6 files changed, 64 insertions, 6 deletions

diff --git a/src/libostree/ostree-fetcher-curl.c b/src/libostree/ostree-fetcher-curl.c
index be3250fb..36bd917b 100644
--- a/src/libostree/ostree-fetcher-curl.c
+++ b/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));
+            {
+              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
                 {
diff --git a/src/libostree/ostree-fetcher-soup.c b/src/libostree/ostree-fetcher-soup.c
index fcdf8e0e..b130b48c 100644
--- a/src/libostree/ostree-fetcher-soup.c
+++ b/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;
         }
diff --git a/src/libostree/ostree-fetcher-util.c b/src/libostree/ostree-fetcher-util.c
index b8af972a..408b8bcb 100644
--- a/src/libostree/ostree-fetcher-util.c
+++ b/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
+}
diff --git a/src/libostree/ostree-fetcher-util.h b/src/libostree/ostree-fetcher-util.h
index 0f25dc30..fe0921cd 100644
--- a/src/libostree/ostree-fetcher-util.h
+++ b/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
diff --git a/src/libostree/ostree-fetcher.h b/src/libostree/ostree-fetcher.h
index f19eb73b..78b29fae 100644
--- a/src/libostree/ostree-fetcher.h
+++ b/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);
diff --git a/src/libostree/ostree-repo-pull.c b/src/libostree/ostree-repo-pull.c
index 3452fbe9..7cbe8f92 100644
--- a/src/libostree/ostree-repo-pull.c
+++ b/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;