From: Lennart Poettering <lennart@poettering.net>
Date: Mon, 25 May 2020 15:13:57 +0000 (+0200)
Subject: efivars: log whenever an EFI variable read access is slow
X-Git-Tag: v246-rc1~278
X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=698564d147ce09c0fedc9de10fe8e0850b729677;p=thirdparty%2Fsystemd.git

efivars: log whenever an EFI variable read access is slow

This should allow us to detect slowdowns caused by EFI variable read
access a bit.
---

diff --git a/src/basic/efivars.c b/src/basic/efivars.c
index b34df46926c..6b6f461446d 100644
--- a/src/basic/efivars.c
+++ b/src/basic/efivars.c
@@ -50,6 +50,7 @@ int efi_get_variable(
         _cleanup_free_ char *p = NULL;
         _cleanup_free_ void *buf = NULL;
         struct stat st;
+        usec_t begin;
         uint32_t a;
         ssize_t n;
 
@@ -68,6 +69,9 @@ int efi_get_variable(
                 return 0;
         }
 
+        if (DEBUG_LOGGING)
+                begin = now(CLOCK_MONOTONIC);
+
         fd = open(p, O_RDONLY|O_NOCTTY|O_CLOEXEC);
         if (fd < 0)
                 return log_debug_errno(errno, "open(\"%s\") failed: %m", p);
@@ -121,6 +125,16 @@ int efi_get_variable(
                 /* Assume that the reported size is accurate */
                 n = st.st_size - 4;
 
+        if (DEBUG_LOGGING) {
+                char ts[FORMAT_TIMESPAN_MAX];
+                usec_t end;
+
+                end = now(CLOCK_MONOTONIC);
+                if (end > begin + EFI_RETRY_DELAY)
+                        log_debug("Detected slow EFI variable read access on " SD_ID128_FORMAT_STR "-%s: %s",
+                                  SD_ID128_FORMAT_VAL(vendor), name, format_timespan(ts, sizeof(ts), end - begin, 1));
+        }
+
         /* Note that efivarfs interestingly doesn't require ftruncate() to update an existing EFI variable
          * with a smaller value. */