Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Bump efivarfs_get_variable throughput to 50 variables/second from 33⅓ #259

Draft
wants to merge 2 commits into
base: main
Choose a base branch
from

Conversation

nabijaczleweli
Copy link
Contributor

@nabijaczleweli nabijaczleweli commented Nov 21, 2023

Read the whole variable at once, then copy out the attributes (for a description of efivarfs rate limiting, see #258).

fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
getdents64(4, 0x55cd1adb8420 /* 104 entries */, 32768) = 7568
getdents64(4, 0x55cd1adb8420 /* 0 entries */, 32768) = 0
close(4)                                = 0
openat(AT_FDCWD, "/sys/firmware/efi/efivars/Boot0002-8be4df61-93ca-11d2-aa0d-00e098032b8c", O_RDONLY) = 4
read(4, "\7\0\0\0\1\0\0\0\r\0U\0E\0F\0I\0:\0C\0D\0/\0D\0V\0D\0"..., 4096) = 59
read(4, "", 4037)                       = 0
close(4)                                = 0
openat(AT_FDCWD, "/sys/firmware/efi/efivars/Boot0003-8be4df61-93ca-11d2-aa0d-00e098032b8c", O_RDONLY) = 4
read(4, "\7\0\0\0\1\0\0\0\r\0U\0E\0F\0I\0:\0R\0e\0m\0o\0v\0a\0"..., 4096) = 67
read(4, "", 4029)                       = 0
close(4)                                = 0
openat(AT_FDCWD, "/sys/firmware/efi/efivars/Boot0004-8be4df61-93ca-11d2-aa0d-00e098032b8c", O_RDONLY) = 4
read(4, "\7\0\0\0\1\0\0\0\r\0U\0E\0F\0I\0:\0N\0e\0t\0w\0o\0r\0"..., 4096) = 63
read(4, "", 4033)                       = 0
close(4)                                = 0
openat(AT_FDCWD, "/sys/firmware/efi/efivars/Boot0005-8be4df61-93ca-11d2-aa0d-00e098032b8c", O_RDONLY) = 4
read(4, "\7\0\0\0\7\0\0\0\314\0D\0e\0b\0i\0a\0n\0 \0G\0N\0U\0/\0"..., 4096) = 610
read(4, "", 3486)                       = 0
close(4)                                = 0
openat(AT_FDCWD, "/sys/firmware/efi/efivars/Boot0006-8be4df61-93ca-11d2-aa0d-00e098032b8c", O_RDONLY) = 4
read(4, "\7\0\0\0\7\0\0\0\314\0D\0e\0b\0i\0a\0n\0 \0G\0N\0U\0/\0"..., 4096) = 610
read(4, "", 3486)                       = 0
close(4)                                = 0
openat(AT_FDCWD, "/sys/firmware/efi/efivars/BootNext-8be4df61-93ca-11d2-aa0d-00e098032b8c", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/sys/firmware/efi/efivars/BootCurrent-8be4df61-93ca-11d2-aa0d-00e098032b8c", O_RDONLY) = 4
read(4, "\6\0\0\0\6\0", 4096)           = 6
read(4, "", 4090)                       = 0
close(4)                                = 0
newfstatat(1, "", {st_mode=S_IFCHR|0620, st_rdev=makedev(0x88, 0x2), ...}, AT_EMPTY_PATH) = 0
write(1, "BootCurrent: 0006\n", 18BootCurrent: 0006
)     = 18
openat(AT_FDCWD, "/sys/firmware/efi/efivars/Timeout-8be4df61-93ca-11d2-aa0d-00e098032b8c", O_RDONLY) = 4
read(4, "\7\0\0\0\1\0", 4096)           = 6
read(4, "", 4090)                       = 0
close(4)                                = 0
write(1, "Timeout: 1 seconds\n", 19Timeout: 1 seconds
)    = 19
openat(AT_FDCWD, "/sys/firmware/efi/efivars/BootOrder-8be4df61-93ca-11d2-aa0d-00e098032b8c", O_RDONLY) = 4
read(4, "\7\0\0\0\6\0\5\0\2\0\3\0\4\0", 4096) = 14
read(4, "", 4082)                       = 0
close(4)                                = 0

Draft because based on #258, otherwise g2g.

…rate limit) for each EFI variable read

Nominally this rate limit is defined to avoid... getting rate-limited?

But it already severely limits the rate to unusable
‒ on two of my real systems this makes efibootmgr take 168ms/194ms,
  which accounts for 95%/82% of the run-time
  (and this is under strace, so it's 100% of the run-time) ‒
for klapki 0.2, this accounts for 36% and a large (140ms!)
start-up delay, and for klapki 0.3 it's well over 50%.
Well before you'd ever run afoul of the real limit.

Discounting "20ms" as "The user is not going to notice." is baffling.
efibootmgr is infuriatingly slow. 20ms is ping-to-america level.

Worse yet, the entire kernel rate-limiter amounts to fs/efivarfs/file.c
-- >8 --
  static ssize_t efivarfs_file_read(struct file *file, char __user *userbuf,
                  size_t count, loff_t *ppos)
  {
          struct efivar_entry *var = file->private_data;
          unsigned long datasize = 0;
          u32 attributes;
          void *data;
          ssize_t size = 0;
          int err;

          while (!__ratelimit(&file->f_cred->user->ratelimit))
                  msleep(50);
-- >8 --
this is the alloc_uid() ratelimit with 1s interval + 100 burst.

This means that we can (best-case) read 50 variables
(read(...), read(0)) instantly, then do so again the next second.

Best-case because the current implementation is broken anyway:
it sleeps for 10ms after the attribute read (sure),
and then for 10ms after the /two/ reads to read the rest of the
variable (bad).

This limits libefivar to 33⅓ variables per second.

Most systems have roughly this many variables. Most programs only
care about a very thin subset of them, and scarcely come close to
reading enough to run afoul of the kernel limit. But even if they
did, this limit is /significantly harsher/ than the kernel limit ‒
it doesn't increase it (how could it? the limit's already there!),
but severely increases latency for /every single read/, instead of
just those over the rate.
It's strictly worse than just not doing it.

This was confirmed experimentally with strace -TTTT /bin/wc * * * * *
(note the many every-variable expansions so it's noticeable):
there is both visually a very obvious "big burst, little slowdown"
oscillation, but also (non-efivarfs reads filtered out)
  $ awk '/^read/ {print $NF}' ss | tr -d '<>' | sort -n | cut -c -6 | uniq -c | sort -n
        1 0.8998
        1 0.9015
        1 0.9581
        1 0.9585
        1 0.9586
        5 0.0013
        9 0.0005
        9 0.0012
       46 0.0011
       70 0.0010
       84 0.0008
       85 0.0009
      102 0.0006
      115 0.0007
or indeed
 $ awk '/^read/ {print $NF}' ss | tr -d '<>' | sort -n | cut -c -5 | uniq -c | sort -n
       1 0.899
       1 0.901
       3 0.958
     130 0.001
     395 0.000
(130+395)/2=262½ variables read in under a millisecond,
and 4½ got limited.

But, much more importantly, the first screenful was free:
99% of programs that don't read every variable
over and over and over, but fit well within the 33
(klapki's 7 and efibootmgr's 8,
 this is with the firmware's base boot entries + two additional ones;
 there isn't a non-hypothetical system in existence with 25 more boot entries).

Fixes: https://bugs.debian.org/1056344
Signed-off-by: Ahelenia Ziemiańska <[email protected]>
Read the whole variable at once, then copy out the attributes
(for a description of efivarfs rate limiting, see rhboot#258)

Signed-off-by: Ahelenia Ziemiańska <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

1 participant