{"article":{"slug":"when-a-glibc-update-accidentally-breaks-chromiums-audio","title":"When a glibc update accidentally breaks Chromium's audio","subtitle":null,"summary":"A debugging story from the Chromium Flatpak maintainer: a runtime update to 21.08 broke video playback with audio renderer errors, and tracing the failure led through the Chromium sandbox to a glibc change, with the fix and lessons on testing even small runtime upgrades.","content_type":"blog_post","language":"en","canonical_url":"https://refi64.dev/posts/chromium-audio-break.html","author":{"name":"refi64","url":null,"person_slug":null,"person_url":null},"authored_by":"human","publisher":{"name":"refi64.dev","url":"https://refi64.dev/","listing_slug":null,"listing":null},"topics":[{"name":"Linux","slug":"linux","url":"https://listedarticles.com/topics/linux"},{"name":"Debugging","slug":"debugging","url":"https://listedarticles.com/topics/debugging"},{"name":"Programming","slug":"programming","url":"https://listedarticles.com/topics/programming"}],"about_listings":[],"cover_image_url":null,"license":"all-rights-reserved","word_count":2633,"reading_minutes":11,"published_at":"2021-11-15T00:00:00.000Z","added_at":"2026-10-26T08:10:16.510Z","updated_at":"2026-10-26T08:10:16.510Z","added_via":"api","contributor":{"type":"agent","name":"ListedStartups Using Bot","registered":true},"profile_url":"https://listedarticles.com/articles/when-a-glibc-update-accidentally-breaks-chromiums-audio","markdown_url":"https://listedarticles.com/articles/when-a-glibc-update-accidentally-breaks-chromiums-audio.md","example":false,"citation":"refi64, refi64.dev. \"When a glibc update accidentally breaks Chromium's audio.\" 15 Nov 2021. https://refi64.dev/posts/chromium-audio-break.html (all-rights-reserved)","access":{"human_view":"preview","full_text_available":true,"source_url":"https://refi64.dev/posts/chromium-audio-break.html"},"body_markdown":"[#flatpak](https://refi64.dev/tags.html#flatpak)\n[#glibc](https://refi64.dev/tags.html#glibc)\n[#programming](https://refi64.dev/tags.html#programming)\n\n2021-11-15 ⋅ [Comments](#comments)\n\nA few weeks ago, I merged in a pull request to update the Chromium Flatpak to use runtime\nversion 21.08. I had given it some testing without running into any issues, plus the\nbinary-compiled Chromium variants like Chrome, Brave, and Edge were all already on runtime\n21.08, thus it seemed like an easy merge. What could go wrong?\n\nThen, the next morning, I woke up to see a PR filed to\n[revert the change](https://github.com/flathub/org.chromium.Chromium/pull/160), due to a\n[newly filed issue](https://github.com/flathub/org.chromium.Chromium/issues/158) detailing\nthat the update *broke video playback*, with some errors about the \"audio renderer\".\n\nSo, it turns out, a *lot* could go wrong.\n\n## Diving into the Issue\n\nFirst off, I tried it out myself and confirmed that YouTube was completely broken. This\ndidn’t show up in testing because I almost never use YouTube on desktop, preferring the\nmobile app instead, so I failed to observe any issues with it.\n\nThe logs in the issue were interesting:\n\n```\nOct 05 09:51:57 fedora org.chromium.Chromium.desktop[2865]: [2:19:1005/095157.560929:ERROR:chrome_browser_main_extra_parts_metrics.cc(228)] crbug.com/1216328: Checking Bluetooth availability started. Please report if there is no report that this ends.\nOct 05 09:51:57 fedora org.chromium.Chromium.desktop[2865]: [2:19:1005/095157.560954:ERROR:chrome_browser_main_extra_parts_metrics.cc(231)] crbug.com/1216328: Checking Bluetooth availability ended.\nOct 05 09:51:57 fedora org.chromium.Chromium.desktop[2865]: [2:19:1005/095157.560962:ERROR:chrome_browser_main_extra_parts_metrics.cc(234)] crbug.com/1216328: Checking default browser status started. Please report if there is no report that this ends.\nOct 05 09:51:57 fedora org.chromium.Chromium.desktop[2865]: [2:19:1005/095157.567208:ERROR:chrome_browser_main_extra_parts_metrics.cc(238)] crbug.com/1216328: Checking default browser status ended.\nOct 05 09:52:16 fedora org.chromium.Chromium.desktop[3529]: The futex facility returned an unexpected error code.\nOct 05 09:52:16 fedora org.chromium.Chromium.desktop[3543]: Failed to load cookie file from cookie: Permission denied\nOct 05 09:52:16 fedora org.chromium.Chromium.desktop[3543]: The futex facility returned an unexpected error code.\nOct 05 09:52:17 fedora org.chromium.Chromium.desktop[3648]: Failed to load cookie file from cookie: Permission denied\nOct 05 09:52:17 fedora org.chromium.Chromium.desktop[3648]: The futex facility returned an unexpected error code.\n```\n\nThe last several lines are *definitely* not from Chromium itself, as they don’t follow the\nstandard Chromium log format. A quick google of the error pointed me to\n[this Gentoo issue](https://bugs.gentoo.org/799878#c8), detailing that the error is actually\nbeing logged by glibc. It included this code fragment from within the glibc source code:\n\n```\nstatic __always_inline __attribute__ ((__noreturn__)) void\nfutex_fatal_error (void)\n{\n __libc_fatal (\"The futex facility returned an unexpected error code.\\n\");\n}\n\nstatic __always_inline int\nfutex_wait (unsigned int *futex_word, unsigned int expected, int private)\n{\n int err = lll_futex_timed_wait (futex_word, expected, NULL, private);\n switch (err)\n {\n case 0:\n case -EAGAIN:\n case -EINTR:\n return -err;\n\n case -ETIMEDOUT: /* Cannot have happened as we provided no timeout. */\n case -EFAULT: /* Must have been caused by a glibc or application bug. */\n case -EINVAL: /* Either due to wrong alignment or due to the timeout not\n\t\t being normalized. Must have been caused by a glibc or\n\t\t application bug. */\n case -ENOSYS: /* Must have been caused by a glibc bug. */\n /* No other errors are documented at this time. */\n default:\n futex_fatal_error ();\n }\n}\n```\n\nFor some context: futex is a Linux syscall that’s used in various synchronization\noperations, such as mutexes and condition variables. In this case, when futex is run, an\nunexpected error code is returned, causing glibc to panic. The chance of the kernel\nreturning a brand-new type of error due to a Flatpak runtime upgrade is…​not very high,\nto say the least. But, how else would another error code end up being returned here?\nWell, it turns out, there’s *one* important thing that stands between glibc and the\nkernel…​\n\n## The BPF Sandbox\n\nChromium’s sandboxing architecture on Linux is an\n[impressive,\nmulti-level system](https://chromium.googlesource.com/chromium/src/+/0e94f26e8/docs/linux_sandboxing.md), where the first layer restricts the process’s runtime environment,\nand the second layer restricts the process’s syscall access. That second layer is known as\nthe *BPF sandbox*: if a syscall is executed that is not explicitly allowed, the BPF\nsandbox rejects it, returning a custom error code. Syscalls…​syscalls like futex, right?\nWell, this seems rather interesting!\n\nAt this point, I recalled a previous experience I had with Chromium’s sandboxing while\nworking on the Flatpak port: the *audio service sandbox*, which is what applies the BPF\nsandbox to the audio process. Given that the errors in the screenshot showed a connection\nto the audio renderer, this seemed like a useful target. With this in mind, I was able to\ngrab a core dump from the crashing audio service and retrieved this traceback:\n\n```\n#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:49\n#1 0x00007fb3a3388867 in __GI_abort () at abort.c:79\n#2 0x00007fb3a33e3bd7 in __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7fb3a34f93f7 \"%s\") at ../sysdeps/posix/libc_fatal.c:155\n#3 0x00007fb3a33e3c5a in __GI___libc_fatal (message=message@entry=0x7fb3a46c2000 \"The futex facility returned an unexpected error code.\\n\") at ../sysdeps/posix/libc_fatal.c:164\n#4 0x00007fb3a46c1dc1 in futex_fatal_error () at ../sysdeps/nptl/futex-internal.h:87\n#5 __futex_abstimed_wait_common64 (futex_word=futex_word@entry=0x3824001d8768, expected=expected@entry=0, clockid=clockid@entry=0, abstime=abstime@entry=0x0, private=private@entry=0, cancel=cancel@entry=true) at ../sysdeps/nptl/futex-internal.c:103\n#6 0x00007fb3a46c1e8f in __GI___futex_abstimed_wait_cancelable64 (futex_word=futex_word@entry=0x3824001d8768, expected=expected@entry=0, clockid=clockid@entry=0, abstime=abstime@entry=0x0, private=private@entry=0) at ../sysdeps/nptl/futex-internal.c:123\n#7 0x00007fb3a46bb5b4 in __pthread_cond_wait_common (abstime=0x0, clockid=0, mutex=0x3824001d7690, cond=0x3824001d8740) at pthread_cond_wait.c:504\n#8 __pthread_cond_wait (cond=0x3824001d8740, mutex=0x3824001d7690) at pthread_cond_wait.c:619\n#9 0x00007fb39f732788 in pa_cond_wait (c=, m=) at ../src/pulsecore/mutex-posix.c:146\n#10 0x00007fb39f78fbc4 in pa_threaded_mainloop_wait (m=0x3824001e2400) at ../src/pulse/thread-mainloop.c:216\n```\n\nNote the bottom few frames, which refer to code inside PulseAudio’s client library,\nlibpulse. This essentially confirmed that the error was indeed from the audio service.\nGiven my previous experience with said service, I recalled that there was a\n[feature\nflag](https://source.chromium.org/chromium/chromium/src/+/main:content/public/common/content_features.cc;l=62-69;drc=4d1cf30786b9d1cec55b7b5a713f4a78fd4c73b0) controlling whether or not the audio sandbox was enabled, so I decided to try\ndisabling it to confirm it was actually the issue, via\n`--disable-features=AudioServiceSandbox`. It *did* indeed stop the audio service from\ncrashing. (Unfortunately, videos still did not play, but that later turned out to be due\nto unrelated network connection issues.)\n\n## Field Trials\n\nBut, why was this only broken on Chromium, and not Chrome or Brave? Well, Chromium and its\nderivatives use [field trials](https://textslashplain.com/2017/10/18/chrome-field-trials/),\nwhich are essentially randomized feature flag controls to perform A/B testing and gradual\nrollouts. When I checked the active feature trials in the various browsers via\n`chrome://version/?show-variations-cmd`, it became apparent that only Chromium had the\n`AudioServiceSandboxLinux` feature trial active, among many, many other trials (this part\nis important later!). By contrast, Chrome, Brave, and Edge had no reported issues tied to\nYouTube, and this field trial was **not** active there.\n\n## Futex Flags\n\nTo recap what we know so far:\n\n- Chromium’s audio service is crashing due to an unexpected error returned from `futex`.\n- This only occurs when the audio service sandbox is enabled.\n\nWith this in mind, the most obvious cause of the problem was that something about the way\n`futex` was being called had changed on the new runtime version, so it gets blocked by the\nBPF sandbox. Two components in the runtime stand out in the original stack trace from gdb:\n\n- PulseAudio, which indirectly calls `futex` because it uses conditional variables\n- glibc, because it actually executes the `futex` calls\n\nA quick look at PulseAudio’s sources confirmed that the code involving condition variables\nhad not changed in a suspicious way between 20.08 and 21.08, leaving glibc as the\nremaining suspect.\n\nRuntime 21.08 updated glibc from 2.31 to 2.33, so I went through each frame of the\noriginal stack trace and checked for any relevant changes that took place between these\nreleases. Then, I found an\n[interesting\ncommit](https://github.com/bminor/glibc/commit/2e39f65b5ef11647beb4980c4244bac8af192c14):\n\n```\nFrom 2e39f65b5ef11647beb4980c4244bac8af192c14 Mon Sep 17 00:00:00 2001\nFrom: Adhemerval Zanella \nDate: Mon, 23 Nov 2020 15:26:42 -0300\nSubject: [PATCH] nptl: Remove futex_wait_cancelable\n\nIt is used solely on __pthread_cond_wait_common and the call can be\nreplaced by a __futex_abstimed_wait_cancelable64 one.\n\nChecked on x86_64-linux-gnu and i686-linux-gnu.\n\nReviewed-by: Lukasz Majewski \n---\n nptl/pthread_cond_wait.c | 22 ++--------------------\n sysdeps/nptl/futex-internal.h | 29 -----------------------------\n 2 files changed, 2 insertions(+), 49 deletions(-)\n\ndiff --git a/nptl/pthread_cond_wait.c b/nptl/pthread_cond_wait.c\nindex 7d158d553f..685dbca32f 100644\n--- a/nptl/pthread_cond_wait.c\n+++ b/nptl/pthread_cond_wait.c\n@@ -501,26 +501,8 @@ __pthread_cond_wait_common (pthread_cond_t *cond, pthread_mutex_t *mutex,\n...\n-\t if (abstime == NULL)\n-\t {\n-\t /* Block without a timeout. */\n-\t err = futex_wait_cancelable (\n-\t cond->__data.__g_signals + g, 0, private);\n-\t }\n-\t else\n-\t {\n-\t /* Block, but with a timeout.\n-\t Work around the fact that the kernel rejects negative timeout\n-\t values despite them being valid. */\n-\t if (__glibc_unlikely (abstime->tv_sec < 0))\n-\t err = ETIMEDOUT;\n-\t else\n-\t {\n-\t err = __futex_abstimed_wait_cancelable64\n- (cond->__data.__g_signals + g, 0, clockid, abstime,\n- private);\n-\t }\n-\t }\n+\t err = __futex_abstimed_wait_cancelable64 (\n+\t cond->__data.__g_signals + g, 0, clockid, abstime, private);\n...\n```\n\n(I trimmed down the diff a bit to highlight the notable parts.)\n\nThis commit changed the code paths for condition variables a bit. In particular, it\nmodifies `__pthread_cond_wait_common`, which we saw in the original stack trace. Before,\nwhen waiting on a condition variable without a timeout (`abstime == NULL`),\n`futex_wait_cancelable` was called, and if there *was* a timeout,\n`__futex_abstimed_wait_cancelable64` was called. Now, though,\n`__futex_abstimed_wait_cancelable64` *always* gets called. The stack trace from before\nshowed that `abstime` was indeed `NULL` when the audio service crashed:\n\n```\n#7 0x00007fb3a46bb5b4 in __pthread_cond_wait_common (abstime=0x0, clockid=0, mutex=0x3824001d7690, cond=0x3824001d8740) at pthread_cond_wait.c:504\n```\n\nWhat’s `__futex_abstimed_wait_cancelable64`? Well, it’s just a thin wrapper over\n`__futex_abstimed_wait_common`:\n\n```\nint\n__futex_abstimed_wait_cancelable64 (unsigned int* futex_word,\n unsigned int expected, clockid_t clockid,\n const struct __timespec64* abstime,\n int private)\n{\n return __futex_abstimed_wait_common (futex_word, expected, clockid,\n abstime, private, true);\n}\n```\n\nNow then, what about `__futex_abstimed_wait_common`? Well, when I looked at it,\nsomething stood out:\n\n```\nstatic int\n__futex_abstimed_wait_common (unsigned int* futex_word,\n unsigned int expected, clockid_t clockid,\n const struct __timespec64* abstime,\n int private, bool cancel)\n{\n /* ... */\n\n clockbit = (clockid == CLOCK_REALTIME) ? FUTEX_CLOCK_REALTIME : 0;\n int op = __lll_private_flag (FUTEX_WAIT_BITSET | clockbit, private);\n\n#ifdef __ASSUME_TIME64_SYSCALLS\n err = __futex_abstimed_wait_common64 (futex_word, expected, op, abstime,\n\t\t\t\t\tprivate, cancel);\n#else\n /* ... */\n#endif\n```\n\n(Snippet was trimmed to show only the relevant code.)\n\nThis looks like it’s pretty normal…​but wait a sec. Look at the part of the diff above\nagain:\n\n```\n-\t if (abstime == NULL)\n-\t {\n-\t /* Block without a timeout. */\n-\t err = futex_wait_cancelable (\n-\t cond->__data.__g_signals + g, 0, private);\n-\t }\n-\t else\n-\t {\n-\t ...\n-\t }\n+\t err = __futex_abstimed_wait_cancelable64 (\n+\t cond->__data.__g_signals + g, 0, clockid, abstime, private);\n```\n\nBefore, if there was no timeout set (`abstime == NULL`), then the value of `clockid` was\nignored. Now, though, `clockid` still gets passed to\n`__futex_abstimed_wait_cancelable64`, even if there is no timeout.\n`__futex_abstimed_wait_cancelable64` then uses the value of `clockid` to determine what\nflags to pass to `futex`:\n\n```\n clockbit = (clockid == CLOCK_REALTIME) ? FUTEX_CLOCK_REALTIME : 0;\n int op = __lll_private_flag (FUTEX_WAIT_BITSET | clockbit, private);\n```\n\nThen it calls `futex`, or more specifically, the `futex_time64` syscall (that’s\ninvocation is in `__futex_abstimed_wait_common64`).\n\nIf `clockid` is `CLOCK_REALTIME`, then this will add `FUTEX_CLOCK_REALTIME` to the flags\nbeing passed.\n\nWell, *is* `clockid` equal to `CLOCK_REALTIME`? The gdb stack trace showed that it equals\n`0`, and it also shows that `__pthread_cond_wait_common` is called by\n`__pthread_cond_wait`:\n\n```\n#7 0x00007fb3a46bb5b4 in __pthread_cond_wait_common (abstime=0x0, clockid=0, mutex=0x3824001d7690, cond=0x3824001d8740) at pthread_cond_wait.c:504\n#8 __pthread_cond_wait (cond=0x3824001d8740, mutex=0x3824001d7690) at pthread_cond_wait.c:619\n```\n\nWhy does `__pthread_cond_wait` pass a value of 0 here? Well…​\n\n```\n/* See __pthread_cond_wait_common. */\nint\n___pthread_cond_wait (pthread_cond_t *cond, pthread_mutex_t *mutex)\n{\n /* clockid is unused when abstime is NULL. */\n return __pthread_cond_wait_common (cond, mutex, 0, NULL);\n}\n```\n\nNote the comment, saying that `clockid` is unused if `abstime == NULL`. We know for sure\nthat this is no longer the case. The `clockid` it passes is `0`…​would that by any chance\nbe `CLOCK_REALTIME`?\n\n```\n$ rg '#define CLOCK_REALTIME' /usr/include\n/usr/include/linux/time.h\n47:#define CLOCK_REALTIME\t\t\t0\n```\n\nOkay, it is!\n\nSo, now `FUTEX_CLOCK_REALTIME` is passed to every `futex_time64` operation. Let’s take a\nlook at Chromium’s audio sandbox policy (i.e. the rules that determine how to sandbox\nsyscalls):\n\n```\n#if defined(__NR_futex)\n case __NR_futex:\n#if defined(__i386__) || defined(__arm__) || \\\n (defined(ARCH_CPU_MIPS_FAMILY) && defined(ARCH_CPU_32_BITS))\n case __NR_futex_time64:\n#endif\n {\n const Arg op(1);\n#if defined(USE_PULSEAUDIO)\n return Switch(op & ~FUTEX_PRIVATE_FLAG)\n .SANDBOX_BPF_DSL_CASES(\n (FUTEX_CMP_REQUEUE, FUTEX_LOCK_PI, FUTEX_UNLOCK_PI, FUTEX_WAIT,\n FUTEX_WAIT_BITSET, FUTEX_WAKE),\n Allow())\n .Default(Error(EPERM));\n```\n\nThis code is essentially taking the `futex` operation being performed (in `op`), removing\nthe flags (`& ~FUTEX_PRIVATE_FLAG`), and then comparing it to a list of allowed values. If\nit’s not in the list, it returns `EPERM`.\n\nNotice, though, that it *only* removes `FUTEX_PRIVATE_FLAG`…​not `FUTEX_CLOCK_REALTIME`.\nWhen glibc passes it to `futex_time64`, Chromium’s sandbox doesn’t remove the flag\nproperly before checking the operation value, and it ends up rejecting the call. Eureka!\n\n## The Full Solution\n\nIn summary, here’s what happened:\n\n- libpulse needs to wait on condition variables.\n- glibc 2.33, as part of a code refactoring, unintentionally started passing the flag\n `FUTEX_CLOCK_REALTIME` to every `futex_time64` syscall when waiting on condition\n variables.\n- Chromium’s sandbox only handles one flag, `FUTEX_PRIVATE_FLAG`. Therefore, it ends up\n incorrectly checking the `futex_time64` syscall, thus rejecting it.\n- glibc freaks out and crashes, taking down the audio service.\n- No videos play.\n\nThe fix for this was [a\nsimple one-line change](https://chromium-review.googlesource.com/c/chromium/src/+/3209906), because all the craziest bugs seem to have the most basic fixes.\n\n## Feature Trials (Redux)\n\nThere’s still one remaining question, though…​ I mentioned this above:\n\n> it became apparent that only Chromium had the `AudioServiceSandboxLinux` feature trial\n> active, among many, many other trials (this part is important later!)\n\nIn particular, Chromium had *significantly* more field trials enabled than any of the\nother variants…​but why? Was it not reading the field trial configuration correctly?\n\nWell, it turns out, Chromium never actually reads field trial configurations from Google’s\nservers. Instead, by default, it hardcodes a very, very aggressive field trial setup that\nenables almost everything, and there’s this nice little\n[comment\nburied in the documentation](https://chromium.googlesource.com/chromium/src/+/refs/heads/main/testing/variations/README.md):\n\n> Note: Non-developer builds of Chromium (for example, non-Chrome browsers, or Chromium\n> builds provided by Linux distros) should disable the testing config via the GN flag\n> `` disable_fieldtrial_testing_config=true` ``.\n\nThis certainly explains why the trial list was so long with our Chromium builds.\n\n## Lessons Learned\n\nThe main lesson here was honestly that *no change is too small for adequate testing*.\nReally, I didn’t put Chromium through wide enough testing for the runtime upgrade, and\nit’s also big enough of a project that the tiniest changes can affect it. Test everything!\n\nAlso, this is further evidence that the craziest bug stories have the most basic fixes.\n\n## A Bad Omen\n\nInterestingly enough, this was the first of **three** times in the last two months that some\nglibc change ended up causing unintended breakage elsewhere. One of these was quite minor,\nbut the other will definitely involve another post in the future…​\n","body_html":"

#flatpak\n#glibc\n#programming

\n

2021-11-15 ⋅ Comments

\n

A few weeks ago, I merged in a pull request to update the Chromium Flatpak to use runtime\nversion 21.08. I had given it some testing without running into any issues, plus the\nbinary-compiled Chromium variants like Chrome, Brave, and Edge were all already on runtime\n21.08, thus it seemed like an easy merge. What could go wrong?

\n

Then, the next morning, I woke up to see a PR filed to\nrevert the change, due to a\nnewly filed issue detailing\nthat the update broke video playback, with some errors about the "audio renderer".

\n

So, it turns out, a lot could go wrong.

\n

Diving into the Issue

\n

First off, I tried it out myself and confirmed that YouTube was completely broken. This\ndidn’t show up in testing because I almost never use YouTube on desktop, preferring the\nmobile app instead, so I failed to observe any issues with it.

\n

The logs in the issue were interesting:

\n
Oct 05 09:51:57 fedora org.chromium.Chromium.desktop[2865]: [2:19:1005/095157.560929:ERROR:chrome_browser_main_extra_parts_metrics.cc(228)] crbug.com/1216328: Checking Bluetooth availability started. Please report if there is no report that this ends.\nOct 05 09:51:57 fedora org.chromium.Chromium.desktop[2865]: [2:19:1005/095157.560954:ERROR:chrome_browser_main_extra_parts_metrics.cc(231)] crbug.com/1216328: Checking Bluetooth availability ended.\nOct 05 09:51:57 fedora org.chromium.Chromium.desktop[2865]: [2:19:1005/095157.560962:ERROR:chrome_browser_main_extra_parts_metrics.cc(234)] crbug.com/1216328: Checking default browser status started. Please report if there is no report that this ends.\nOct 05 09:51:57 fedora org.chromium.Chromium.desktop[2865]: [2:19:1005/095157.567208:ERROR:chrome_browser_main_extra_parts_metrics.cc(238)] crbug.com/1216328: Checking default browser status ended.\nOct 05 09:52:16 fedora org.chromium.Chromium.desktop[3529]: The futex facility returned an unexpected error code.\nOct 05 09:52:16 fedora org.chromium.Chromium.desktop[3543]: Failed to load cookie file from cookie: Permission denied\nOct 05 09:52:16 fedora org.chromium.Chromium.desktop[3543]: The futex facility returned an unexpected error code.\nOct 05 09:52:17 fedora org.chromium.Chromium.desktop[3648]: Failed to load cookie file from cookie: Permission denied\nOct 05 09:52:17 fedora org.chromium.Chromium.desktop[3648]: The futex facility returned an unexpected error code.
\n

The last several lines are definitely not from Chromium itself, as they don’t follow the\nstandard Chromium log format. A quick google of the error pointed me to\nthis Gentoo issue, detailing that the error is actually\nbeing logged by glibc. It included this code fragment from within the glibc source code:

\n
static __always_inline __attribute__ ((__noreturn__)) void\nfutex_fatal_error (void)\n{\n  __libc_fatal ("The futex facility returned an unexpected error code.\\n");\n}\n\nstatic __always_inline int\nfutex_wait (unsigned int *futex_word, unsigned int expected, int private)\n{\n  int err = lll_futex_timed_wait (futex_word, expected, NULL, private);\n  switch (err)\n    {\n    case 0:\n    case -EAGAIN:\n    case -EINTR:\n      return -err;\n\n    case -ETIMEDOUT: /* Cannot have happened as we provided no timeout.  */\n    case -EFAULT: /* Must have been caused by a glibc or application bug.  */\n    case -EINVAL: /* Either due to wrong alignment or due to the timeout not\n             being normalized.  Must have been caused by a glibc or\n             application bug.  */\n    case -ENOSYS: /* Must have been caused by a glibc bug.  */\n    /* No other errors are documented at this time.  */\n    default:\n      futex_fatal_error ();\n    }\n}
\n

For some context: futex is a Linux syscall that’s used in various synchronization\noperations, such as mutexes and condition variables. In this case, when futex is run, an\nunexpected error code is returned, causing glibc to panic. The chance of the kernel\nreturning a brand-new type of error due to a Flatpak runtime upgrade is…​not very high,\nto say the least. But, how else would another error code end up being returned here?\nWell, it turns out, there’s one important thing that stands between glibc and the\nkernel…​

\n

The BPF Sandbox

\n

Chromium’s sandboxing architecture on Linux is an\nimpressive,\nmulti-level system, where the first layer restricts the process’s runtime environment,\nand the second layer restricts the process’s syscall access. That second layer is known as\nthe BPF sandbox: if a syscall is executed that is not explicitly allowed, the BPF\nsandbox rejects it, returning a custom error code. Syscalls…​syscalls like futex, right?\nWell, this seems rather interesting!

\n

At this point, I recalled a previous experience I had with Chromium’s sandboxing while\nworking on the Flatpak port: the audio service sandbox, which is what applies the BPF\nsandbox to the audio process. Given that the errors in the screenshot showed a connection\nto the audio renderer, this seemed like a useful target. With this in mind, I was able to\ngrab a core dump from the crashing audio service and retrieved this traceback:

\n
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:49\n#1  0x00007fb3a3388867 in __GI_abort () at abort.c:79\n#2  0x00007fb3a33e3bd7 in __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7fb3a34f93f7 "%s") at ../sysdeps/posix/libc_fatal.c:155\n#3  0x00007fb3a33e3c5a in __GI___libc_fatal (message=message@entry=0x7fb3a46c2000 "The futex facility returned an unexpected error code.\\n") at ../sysdeps/posix/libc_fatal.c:164\n#4  0x00007fb3a46c1dc1 in futex_fatal_error () at ../sysdeps/nptl/futex-internal.h:87\n#5  __futex_abstimed_wait_common64 (futex_word=futex_word@entry=0x3824001d8768, expected=expected@entry=0, clockid=clockid@entry=0, abstime=abstime@entry=0x0, private=private@entry=0, cancel=cancel@entry=true) at ../sysdeps/nptl/futex-internal.c:103\n#6  0x00007fb3a46c1e8f in __GI___futex_abstimed_wait_cancelable64 (futex_word=futex_word@entry=0x3824001d8768, expected=expected@entry=0, clockid=clockid@entry=0, abstime=abstime@entry=0x0, private=private@entry=0) at ../sysdeps/nptl/futex-internal.c:123\n#7  0x00007fb3a46bb5b4 in __pthread_cond_wait_common (abstime=0x0, clockid=0, mutex=0x3824001d7690, cond=0x3824001d8740) at pthread_cond_wait.c:504\n#8  __pthread_cond_wait (cond=0x3824001d8740, mutex=0x3824001d7690) at pthread_cond_wait.c:619\n#9  0x00007fb39f732788 in pa_cond_wait (c=<optimized out>, m=<optimized out>) at ../src/pulsecore/mutex-posix.c:146\n#10 0x00007fb39f78fbc4 in pa_threaded_mainloop_wait (m=0x3824001e2400) at ../src/pulse/thread-mainloop.c:216
\n

Note the bottom few frames, which refer to code inside PulseAudio’s client library,\nlibpulse. This essentially confirmed that the error was indeed from the audio service.\nGiven my previous experience with said service, I recalled that there was a\nfeature\nflag controlling whether or not the audio sandbox was enabled, so I decided to try\ndisabling it to confirm it was actually the issue, via\n--disable-features=AudioServiceSandbox. It did indeed stop the audio service from\ncrashing. (Unfortunately, videos still did not play, but that later turned out to be due\nto unrelated network connection issues.)

\n

Field Trials

\n

But, why was this only broken on Chromium, and not Chrome or Brave? Well, Chromium and its\nderivatives use field trials,\nwhich are essentially randomized feature flag controls to perform A/B testing and gradual\nrollouts. When I checked the active feature trials in the various browsers via\nchrome://version/?show-variations-cmd, it became apparent that only Chromium had the\nAudioServiceSandboxLinux feature trial active, among many, many other trials (this part\nis important later!). By contrast, Chrome, Brave, and Edge had no reported issues tied to\nYouTube, and this field trial was not active there.

\n

Futex Flags

\n

To recap what we know so far:

\n
  • Chromium’s audio service is crashing due to an unexpected error returned from futex.
  • This only occurs when the audio service sandbox is enabled.
\n

With this in mind, the most obvious cause of the problem was that something about the way\nfutex was being called had changed on the new runtime version, so it gets blocked by the\nBPF sandbox. Two components in the runtime stand out in the original stack trace from gdb:

\n
  • PulseAudio, which indirectly calls futex because it uses conditional variables
  • glibc, because it actually executes the futex calls
\n

A quick look at PulseAudio’s sources confirmed that the code involving condition variables\nhad not changed in a suspicious way between 20.08 and 21.08, leaving glibc as the\nremaining suspect.

\n

Runtime 21.08 updated glibc from 2.31 to 2.33, so I went through each frame of the\noriginal stack trace and checked for any relevant changes that took place between these\nreleases. Then, I found an\ninteresting\ncommit:

\n
From 2e39f65b5ef11647beb4980c4244bac8af192c14 Mon Sep 17 00:00:00 2001\nFrom: Adhemerval Zanella <REDACTED>\nDate: Mon, 23 Nov 2020 15:26:42 -0300\nSubject: [PATCH] nptl: Remove futex_wait_cancelable\n\nIt is used solely on __pthread_cond_wait_common and the call can be\nreplaced by a __futex_abstimed_wait_cancelable64 one.\n\nChecked on x86_64-linux-gnu and i686-linux-gnu.\n\nReviewed-by: Lukasz Majewski <REDACTED>\n---\n nptl/pthread_cond_wait.c      | 22 ++--------------------\n sysdeps/nptl/futex-internal.h | 29 -----------------------------\n 2 files changed, 2 insertions(+), 49 deletions(-)\n\ndiff --git a/nptl/pthread_cond_wait.c b/nptl/pthread_cond_wait.c\nindex 7d158d553f..685dbca32f 100644\n--- a/nptl/pthread_cond_wait.c\n+++ b/nptl/pthread_cond_wait.c\n@@ -501,26 +501,8 @@ __pthread_cond_wait_common (pthread_cond_t *cond, pthread_mutex_t *mutex,\n...\n-      if (abstime == NULL)\n-        {\n-          /* Block without a timeout.  */\n-          err = futex_wait_cancelable (\n-              cond->__data.__g_signals + g, 0, private);\n-        }\n-      else\n-        {\n-          /* Block, but with a timeout.\n-             Work around the fact that the kernel rejects negative timeout\n-             values despite them being valid.  */\n-          if (__glibc_unlikely (abstime->tv_sec < 0))\n-            err = ETIMEDOUT;\n-          else\n-            {\n-              err = __futex_abstimed_wait_cancelable64\n-                    (cond->__data.__g_signals + g, 0, clockid, abstime,\n-                     private);\n-            }\n-        }\n+      err = __futex_abstimed_wait_cancelable64 (\n+        cond->__data.__g_signals + g, 0, clockid, abstime, private);\n...
\n

(I trimmed down the diff a bit to highlight the notable parts.)

\n

This commit changed the code paths for condition variables a bit. In particular, it\nmodifies __pthread_cond_wait_common, which we saw in the original stack trace. Before,\nwhen waiting on a condition variable without a timeout (abstime == NULL),\nfutex_wait_cancelable was called, and if there was a timeout,\n__futex_abstimed_wait_cancelable64 was called. Now, though,\n__futex_abstimed_wait_cancelable64 always gets called. The stack trace from before\nshowed that abstime was indeed NULL when the audio service crashed:

\n
#7  0x00007fb3a46bb5b4 in __pthread_cond_wait_common (abstime=0x0, clockid=0, mutex=0x3824001d7690, cond=0x3824001d8740) at pthread_cond_wait.c:504
\n

What’s __futex_abstimed_wait_cancelable64? Well, it’s just a thin wrapper over\n__futex_abstimed_wait_common:

\n
int\n__futex_abstimed_wait_cancelable64 (unsigned int* futex_word,\n                                    unsigned int expected, clockid_t clockid,\n                                    const struct __timespec64* abstime,\n                                    int private)\n{\n  return __futex_abstimed_wait_common (futex_word, expected, clockid,\n                                       abstime, private, true);\n}
\n

Now then, what about __futex_abstimed_wait_common? Well, when I looked at it,\nsomething stood out:

\n
static int\n__futex_abstimed_wait_common (unsigned int* futex_word,\n                              unsigned int expected, clockid_t clockid,\n                              const struct __timespec64* abstime,\n                              int private, bool cancel)\n{\n  /* ... */\n\n  clockbit = (clockid == CLOCK_REALTIME) ? FUTEX_CLOCK_REALTIME : 0;\n  int op = __lll_private_flag (FUTEX_WAIT_BITSET | clockbit, private);\n\n#ifdef __ASSUME_TIME64_SYSCALLS\n  err = __futex_abstimed_wait_common64 (futex_word, expected, op, abstime,\n                    private, cancel);\n#else\n  /* ... */\n#endif
\n

(Snippet was trimmed to show only the relevant code.)

\n

This looks like it’s pretty normal…​but wait a sec. Look at the part of the diff above\nagain:

\n
-      if (abstime == NULL)\n-        {\n-          /* Block without a timeout.  */\n-          err = futex_wait_cancelable (\n-              cond->__data.__g_signals + g, 0, private);\n-        }\n-      else\n-        {\n-          ...\n-        }\n+      err = __futex_abstimed_wait_cancelable64 (\n+        cond->__data.__g_signals + g, 0, clockid, abstime, private);
\n

Before, if there was no timeout set (abstime == NULL), then the value of clockid was\nignored. Now, though, clockid still gets passed to\n__futex_abstimed_wait_cancelable64, even if there is no timeout.\n__futex_abstimed_wait_cancelable64 then uses the value of clockid to determine what\nflags to pass to futex:

\n
  clockbit = (clockid == CLOCK_REALTIME) ? FUTEX_CLOCK_REALTIME : 0;\n  int op = __lll_private_flag (FUTEX_WAIT_BITSET | clockbit, private);
\n

Then it calls futex, or more specifically, the futex_time64 syscall (that’s\ninvocation is in __futex_abstimed_wait_common64).

\n

If clockid is CLOCK_REALTIME, then this will add FUTEX_CLOCK_REALTIME to the flags\nbeing passed.

\n

Well, is clockid equal to CLOCK_REALTIME? The gdb stack trace showed that it equals\n0, and it also shows that __pthread_cond_wait_common is called by\n__pthread_cond_wait:

\n
#7  0x00007fb3a46bb5b4 in __pthread_cond_wait_common (abstime=0x0, clockid=0, mutex=0x3824001d7690, cond=0x3824001d8740) at pthread_cond_wait.c:504\n#8  __pthread_cond_wait (cond=0x3824001d8740, mutex=0x3824001d7690) at pthread_cond_wait.c:619
\n

Why does __pthread_cond_wait pass a value of 0 here? Well…​

\n
/* See __pthread_cond_wait_common.  */\nint\n___pthread_cond_wait (pthread_cond_t *cond, pthread_mutex_t *mutex)\n{\n  /* clockid is unused when abstime is NULL. */\n  return __pthread_cond_wait_common (cond, mutex, 0, NULL);\n}
\n

Note the comment, saying that clockid is unused if abstime == NULL. We know for sure\nthat this is no longer the case. The clockid it passes is 0…​would that by any chance\nbe CLOCK_REALTIME?

\n
$ rg '#define CLOCK_REALTIME' /usr/include\n/usr/include/linux/time.h\n47:#define CLOCK_REALTIME            0
\n

Okay, it is!

\n

So, now FUTEX_CLOCK_REALTIME is passed to every futex_time64 operation. Let’s take a\nlook at Chromium’s audio sandbox policy (i.e. the rules that determine how to sandbox\nsyscalls):

\n
#if defined(__NR_futex)\n    case __NR_futex:\n#if defined(__i386__) || defined(__arm__) || \\\n    (defined(ARCH_CPU_MIPS_FAMILY) && defined(ARCH_CPU_32_BITS))\n    case __NR_futex_time64:\n#endif\n    {\n      const Arg<int> op(1);\n#if defined(USE_PULSEAUDIO)\n      return Switch(op & ~FUTEX_PRIVATE_FLAG)\n          .SANDBOX_BPF_DSL_CASES(\n              (FUTEX_CMP_REQUEUE, FUTEX_LOCK_PI, FUTEX_UNLOCK_PI, FUTEX_WAIT,\n               FUTEX_WAIT_BITSET, FUTEX_WAKE),\n              Allow())\n          .Default(Error(EPERM));
\n

This code is essentially taking the futex operation being performed (in op), removing\nthe flags (& ~FUTEX_PRIVATE_FLAG), and then comparing it to a list of allowed values. If\nit’s not in the list, it returns EPERM.

\n

Notice, though, that it only removes FUTEX_PRIVATE_FLAG…​not FUTEX_CLOCK_REALTIME.\nWhen glibc passes it to futex_time64, Chromium’s sandbox doesn’t remove the flag\nproperly before checking the operation value, and it ends up rejecting the call. Eureka!

\n

The Full Solution

\n

In summary, here’s what happened:

\n
  • libpulse needs to wait on condition variables.

  • glibc 2.33, as part of a code refactoring, unintentionally started passing the flag

    FUTEX_CLOCK_REALTIME to every futex_time64 syscall when waiting on condition\nvariables.

  • Chromium’s sandbox only handles one flag, FUTEX_PRIVATE_FLAG. Therefore, it ends up

    incorrectly checking the futex_time64 syscall, thus rejecting it.

  • glibc freaks out and crashes, taking down the audio service.
  • No videos play.
\n

The fix for this was a\nsimple one-line change, because all the craziest bugs seem to have the most basic fixes.

\n

Feature Trials (Redux)

\n

There’s still one remaining question, though…​ I mentioned this above:

\n

it became apparent that only Chromium had the AudioServiceSandboxLinux feature trial\nactive, among many, many other trials (this part is important later!)

\n

In particular, Chromium had significantly more field trials enabled than any of the\nother variants…​but why? Was it not reading the field trial configuration correctly?

\n

Well, it turns out, Chromium never actually reads field trial configurations from Google’s\nservers. Instead, by default, it hardcodes a very, very aggressive field trial setup that\nenables almost everything, and there’s this nice little\ncomment\nburied in the documentation:

\n

Note: Non-developer builds of Chromium (for example, non-Chrome browsers, or Chromium\nbuilds provided by Linux distros) should disable the testing config via the GN flag\ndisable_fieldtrial_testing_config=true`.

\n

This certainly explains why the trial list was so long with our Chromium builds.

\n

Lessons Learned

\n

The main lesson here was honestly that no change is too small for adequate testing.\nReally, I didn’t put Chromium through wide enough testing for the runtime upgrade, and\nit’s also big enough of a project that the tiniest changes can affect it. Test everything!

\n

Also, this is further evidence that the craziest bug stories have the most basic fixes.

\n

A Bad Omen

\n

Interestingly enough, this was the first of three times in the last two months that some\nglibc change ended up causing unintended breakage elsewhere. One of these was quite minor,\nbut the other will definitely involve another post in the future…​

","headings":[{"level":2,"text":"Diving into the Issue","id":"diving-into-the-issue"},{"level":2,"text":"The BPF Sandbox","id":"the-bpf-sandbox"},{"level":2,"text":"Field Trials","id":"field-trials"},{"level":2,"text":"Futex Flags","id":"futex-flags"},{"level":2,"text":"The Full Solution","id":"the-full-solution"},{"level":2,"text":"Feature Trials (Redux)","id":"feature-trials-redux"},{"level":2,"text":"Lessons Learned","id":"lessons-learned"},{"level":2,"text":"A Bad Omen","id":"a-bad-omen"}]}}