Closed Bug 1921742 Opened 1 year ago Closed 1 year ago

Firefox spamming logs in journald about shader cache

Categories

(Core :: Graphics: WebRender, defect)

Product:
Core
Component:
Graphics: WebRender
Version:
Firefox 130
Platform:
x86_64
Linux
Type:
defect

Tracking

()

Status:
RESOLVED DUPLICATE of bug 1947617

People

(Reporter: liangrui.ch, Unassigned)

Details

Attachments

(6 files)

troubleshooting-info-ncfavier
51.27 KB, text/plain
Details
firefox-info.txt
97.59 KB, text/plain
Details
firefox-info.txt
102.14 KB, application/json
Details
firefox-support.txt
41.26 KB, text/plain
Details
firefox_copy.txt
21.79 KB, text/plain
Details
firefox_raw.txt
88.68 KB, text/plain
Details

User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:130.0) Gecko/20100101 Firefox/130.0

Steps to reproduce:

I' m using Arch Linux as my daily drive.

I used journalctl to check systemd yesterday and I found out that Firefox reports a lot of error message like
"firefox[137614]: Failed to create /home/bryan/.cache for shader cache (Permission denied)---disabling."

The first error message is on Sep 6, which is the day I upgrade my system, and Firefox is upgraded to 130 from 129.

As far I notice that once I visit some video platform like youtube, Firefox keep reporting this error. Here is the screen record of this phenomenon: https://vimeo.com/1014038156?share=copy.

Actual results:

Firefox reports a lot of error in journald

Expected results:

There is no error message.

Here is my system information:

Operating System: Arch Linux
KDE Plasma Version: 6.1.5
KDE Frameworks Version: 6.6.0
Qt Version: 6.7.3
Kernel Version: 6.10.10-zen1-1-zen-cjktty (64-bit)
Graphics Platform: Wayland
Processors: 16 × AMD Ryzen 7 5800H with Radeon Graphics
Memory: 13.5 GiB of RAM
Graphics Processor: AMD Radeon Graphics

I have checked the permission of related directory, but I did not find something abnormal.

bryan on Bryan-YOGA14s in ~ took 14s 
❯ LC_ALL=C stat .cache/
  File: .cache/
  Size: 1882            Blocks: 8          IO Block: 4096   directory
Device: 0,50    Inode: 450         Links: 1
Access: (0755/drwxr-xr-x)  Uid: ( 1000/   bryan)   Gid: ( 1000/   bryan)
Access: 2024-09-30 17:35:59.542560487 +0800
Modify: 2024-09-30 17:18:38.967434371 +0800
Change: 2024-09-30 17:18:38.967434371 +0800
 Birth: 2024-08-18 08:55:18.030328424 +0800
bryan on Bryan-YOGA14s in ~ 
❯ LC_ALL=C stat .cache/mesa_shader_cache/ .cache/mesa_shader_cache_db/
  File: .cache/mesa_shader_cache/
  Size: 0               Blocks: 0          IO Block: 4096   directory
Device: 0,50    Inode: 1764403     Links: 1
Access: (0700/drwx------)  Uid: ( 1000/   bryan)   Gid: ( 1000/   bryan)
Access: 2024-09-30 01:19:23.555762340 +0800
Modify: 2024-09-26 22:32:24.124328934 +0800
Change: 2024-09-26 22:32:24.124328934 +0800
 Birth: 2024-09-26 22:32:24.124328934 +0800
  File: .cache/mesa_shader_cache_db/
  Size: 602             Blocks: 0          IO Block: 4096   directory
Device: 0,50    Inode: 1764404     Links: 1
Access: (0700/drwx------)  Uid: ( 1000/   bryan)   Gid: ( 1000/   bryan)
Access: 2024-09-30 01:19:23.555762340 +0800
Modify: 2024-09-26 22:32:24.144328955 +0800
Change: 2024-09-26 22:32:24.144328955 +0800
 Birth: 2024-09-26 22:32:24.124328934 +0800
OS: Unspecified → Linux
Hardware: Unspecified → x86_64

The Bugbug bot thinks this bug should belong to the 'Core::Graphics: WebRender' component, and is moving the bug to that component. Please correct in case you think the bot is wrong.

Component: Untriaged → Graphics: WebRender
Product: Firefox → Core

Can you go to about:support in Firefox and click either one of the two copy to clipboard buttons at the top of that page and paste into an attachment on this bug? It has information about your OpenGL drivers and decisions the browser made on how to play media such as video streams which may be relevant.

Severity: -- → S3
Flags: needinfo?(liangrui.ch)

I'm having the same issue, here's my info.

Attached file firefox-info.txt —

Here is my firefox information.

Flags: needinfo?(liangrui.ch)

(In reply to Ashley Hale [:ahale] from comment #4)

Can you go to about:support in Firefox and click either one of the two copy to clipboard buttons at the top of that page and paste into an attachment on this bug? It has information about your OpenGL drivers and decisions the browser made on how to play media such as video streams which may be relevant.

Sorry for replying late, I uploaded my firefox information just now.

The same thing is happening for me with the Flatpak for the location ~/.var/app/org.mozilla.firefox/cache, and I attached my about:support information as well in case it helps to narrow the problem down.

Attached file firefox-info.txt —

I started looking into this issues as well. My system:

Distro: EndeavourOS (ARCH)
Kernel: 6.11.9-zen1-1-zen arch: x86_64 bits: 64
Desktop: GNOME v: 47.2
Firefox 133 (native package).

I notice when I start Firefox and it needs to use mesa shaders it creates the two following directories:

~/.cache/mesa_shader_cache_db
~/.cache/mesa_shader_cache

I did try deleting these directories and let them re-create to make sure they had the expected permissions:

drwx------    2 user user     4096 Dec  9 17:31  mesa_shader_cache
drwx------   52 user user     4096 Dec  9 17:31  mesa_shader_cache_db

When I run firefox from terminal I will get the follow messages when a video starts playing:

❯ firefox
Failed to create /home for shader cache (Permission denied)---disabling.
Failed to create /home for shader cache (Permission denied)---disabling.
Unsupported modifier, resource creation failed.

I will attach my firefox support details to help with the issue.

Attached file firefox-support.txt —

(In reply to liangrui.ch from comment #7)

(In reply to Ashley Hale [:ahale] from comment #4)

Can you go to about:support in Firefox and click either one of the two copy to clipboard buttons at the top of that page and paste into an attachment on this bug? It has information about your OpenGL drivers and decisions the browser made on how to play media such as video streams which may be relevant.

Sorry for replying late, I uploaded my firefox information just now.

Hi Liang,

I was wondering if you tried downgrading Firefox to a previous release to see if the error went away?

Thanks

Failed to create /home for shader cache (Permission denied)---disabling.

Exact same message here, also using Arch w/ kernel 6.12.4 and firefox 133.0.

(In reply to rsramkis from comment #12)

(In reply to liangrui.ch from comment #7)

(In reply to Ashley Hale [:ahale] from comment #4)

Can you go to about:support in Firefox and click either one of the two copy to clipboard buttons at the top of that page and paste into an attachment on this bug? It has information about your OpenGL drivers and decisions the browser made on how to play media such as video streams which may be relevant.

Sorry for replying late, I uploaded my firefox information just now.

Hi Liang,

I was wondering if you tried downgrading Firefox to a previous release to see if the error went away?

Thanks

No, but I'm sure that the error message came after Firefox 130.

Can also confirm this bug is happening for me as well. Also on Firefox 133.0.3.

(In reply to Ashley Hale [:ahale] from comment #4)

Can you go to about:support in Firefox and click either one of the two copy to clipboard buttons at the top of that page and paste into an attachment on this bug? It has information about your OpenGL drivers and decisions the browser made on how to play media such as video streams which may be relevant.

Hi Ashley,

Is there an update on where we are with this bug? There are multiple people reporting the issue as re-producible. Can we get anything else to help you complete the root cause analysis?

Just to confirm the same issue: Failed to create /var for shader cache (Permission denied)---disabling:

dec 29 22:02:58 fedora org.mozilla.firefox.desktop[75880]: libva info: VA-API version 1.19.0
dec 29 22:02:58 fedora org.mozilla.firefox.desktop[75880]: libva info: Trying to open /usr/lib/x86_64-linux-gnu/dri/radeonsi_drv_video.so
dec 29 22:02:58 fedora org.mozilla.firefox.desktop[75880]: libva info: Trying to open /usr/lib/x86_64-linux-gnu/dri/intel-vaapi-driver/radeonsi_drv_video.so
dec 29 22:02:58 fedora org.mozilla.firefox.desktop[75880]: libva info: Trying to open /usr/lib/x86_64-linux-gnu/GL/lib/dri/radeonsi_drv_video.so
dec 29 22:02:58 fedora org.mozilla.firefox.desktop[75880]: libva info: Found init function __vaDriverInit_1_19
dec 29 22:02:58 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:02:58 fedora org.mozilla.firefox.desktop[75880]: libva info: va_openDriver() returns 0
dec 29 22:03:01 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:06 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:07 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:07 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:07 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:07 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:07 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:07 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:07 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:07 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:07 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:07 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:07 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:07 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:07 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:07 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:08 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:08 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:08 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:08 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:08 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:08 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:08 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:08 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:08 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:08 fedora bluetoothd[1418]: Player registered: sender=:1.35 path=/_1_984
dec 29 22:03:08 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:08 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:08 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:08 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.
dec 29 22:03:08 fedora org.mozilla.firefox.desktop[75880]: Failed to create /var for shader cache (Permission denied)---disabling.

Attached file firefox_copy.txt —
Attached file firefox_raw.txt —

I'm using a hybrid stack, and on Fedora Silverblue.

It seems very unstable, and I do get a low performance.

Getting the same message on system's installed Firefox on OpenSUSE Tumbleweed.

On a first glance it looks like some sandboxed Firefox process does not have rights to stat() in arbitrary directories.

Seems to be caused by the code at https://searchfox.org/mozilla-central/source/third_party/rust/glslopt/glsl-optimizer/src/util/disk_cache.c#149

   if (stat(path, &sb) == 0) {
      if (S_ISDIR(sb.st_mode)) {
         return 0;
      } else {
         fprintf(stderr, "Cannot use %s for shader cache (not a directory)"
                         "---disabling.\n", path);
         return -1;
      }
   }

Correction on the above message. The error message is very similar but different to the one I mentioned. Seems to be coming from a few lines under in the same file https://searchfox.org/mozilla-central/source/third_party/rust/glslopt/glsl-optimizer/src/util/disk_cache.c#159

   int ret = mkdir(path, 0755);
   if (ret == 0 || (ret == -1 && errno == EEXIST))
     return 0;

   fprintf(stderr, "Failed to create %s for shader cache (%s)---disabling.\n",
           path, strerror(errno));

   return -1;

So it's an error on mkdir(), not on stat that I erroneously mentioned. My assumption then is wrong, it's not a sandbox error, as no user process should mkdir() on these system directories.

Could you please try setting MESA_SHADER_CACHE_DIR? (see https://github.com/flathub/io.gitlab.librewolf-community/pull/145/files)

For some reason I did get this at first on the Firefox flatpak, but after forcing VA-API/HWAccel, the issue went away.
I don't know why.

I analyzed the problem, and indeed the issue is triggered by a sub-process with limited privilege/sandboxed.
It looks like this message log does not have any impact

Here the functions called by disk_cache_create() in mesa source code:

  • disk_cache_delete_old_cache() is only called if MESA_SHADER_CACHE_DIR is not defined
    • disk_cache_generate_cache_dir()
    • mkdir_if_needed("/home") failed to stat()
  • disk_cache_type_create()
    • disk_cache_enabled() is called, if cache is disabled (disabled if not a __normal_user()), do nothing and return.
    • disk_cache_generate_cache_dir() (is not called if cache is disabled). So this call never trigger the warning

So defining MESA_SHADER_CACHE_DIR prevent the delete of the cache, and so no warning is displayed.

To fix this the following patch is needed in mesa (I will try to submit it):
Add the following lines at the beginning of disk_cache_delete_old_cache():

   if (!disk_cache_enabled())
      return;

(In reply to benjarobin from comment #26)

Fix the issue in this MR: https://gitlab.freedesktop.org/mesa/mesa/-/merge_requests/32886

If you have a local install (from Arch repository) and not a Flatpak, there a work around to stop the spamming?

On my own I did the following:

  1. Deleted the two directories:
~/.cache/mesa_shader_cache_db
~/.cache/mesa_shader_cache
  1. Added the following to the " ~/.config/environment.d/envvars.conf " file:
MESA_SHADER_CACHE_DIR=/home/testuser/.cache/mesa_shader_cache
  1. After reboot and launching Firefox and playing a video I did see the directories get recreated:
/home/testuser/.cache/mesa_shader_cache
/home/testuser/.cache/mesa_shader_cache/mesa_shader_cache_db

But I am still seeing the journal filling up with the same error messages.

(In reply to rsramkis from comment #27)

(In reply to benjarobin from comment #26)

Fix the issue in this MR: https://gitlab.freedesktop.org/mesa/mesa/-/merge_requests/32886

If you have a local install (from Arch repository) and not a Flatpak, there a work around to stop the spamming?

On my own I did the following:

  1. Deleted the two directories:
~/.cache/mesa_shader_cache_db
~/.cache/mesa_shader_cache
  1. Added the following to the " ~/.config/environment.d/envvars.conf " file:
MESA_SHADER_CACHE_DIR=/home/testuser/.cache/mesa_shader_cache
  1. After reboot and launching Firefox and playing a video I did see the directories get recreated:
/home/testuser/.cache/mesa_shader_cache
/home/testuser/.cache/mesa_shader_cache/mesa_shader_cache_db

But I am still seeing the journal filling up with the same error messages.

Did you try setting using this as a local env var, e.g. prefix this with the Firefox command?

I also enabled video HWAccel, but I don't know if this prevents the shader cache from being used, thus preventing the error.

(In reply to rsramkis from comment #27)

But I am still seeing the journal filling up with the same error messages.

From a terminal, is the environment variable MESA_SHADER_CACHE_DIR set? What is the output of: echo $MESA_SHADER_CACHE_DIR
If the environment variable MESA_SHADER_CACHE_DIR is indeed set, close all Firefox window / process, then launch Firefox from that terminal. Do you have still these errors messages, and if this is the case, what is the error exactly?

(In reply to benjarobin from comment #29)

(In reply to rsramkis from comment #27)

But I am still seeing the journal filling up with the same error messages.

From a terminal, is the environment variable MESA_SHADER_CACHE_DIR set? What is the output of: echo $MESA_SHADER_CACHE_DIR
If the environment variable MESA_SHADER_CACHE_DIR is indeed set, close all Firefox window / process, then launch Firefox from that terminal. Do you have still these errors messages, and if this is the case, what is the error exactly?

This is what I am seeing after I reset my test:

❯ echo $MESA_SHADER_CACHE_DIR
/home/rsruser/.cache/mesa_shader_cache

~
❯ firefox
Unsupported modifier, resource creation failed.
Unsupported modifier, resource creation failed.
Unsupported modifier, resource creation failed.
Unsupported modifier, resource creation failed.
Unsupported modifier, resource creation failed.
Unsupported modifier, resource creation failed.
Unsupported modifier, resource creation failed.

As long as the video is playing the screen will fill up with the out put of "Unsupported modifier, resource creation failed.".

(In reply to rsramkis from comment #30)

Unsupported modifier, resource creation failed.

This is another issue, complete unrelated to this ticket/bug report. You should create another bug report for that

(In reply to benjarobin from comment #31)

(In reply to rsramkis from comment #30)

Unsupported modifier, resource creation failed.

This is another issue, complete unrelated to this ticket/bug report. You should create another bug report for that

I can create another bug (but then this one has been sitting around for 4 months). The "Unsupported modifier, resource creation failed." only shows up when playing a video (e.g. https://www.youtube.com/live/6nCNlI_0-KU?si=rW9M_Z9F1h0JSIxx).

This is the output without an environment variable:

❯ firefox
Failed to create /home for shader cache (Permission denied)---disabling.
Failed to create /home for shader cache (Permission denied)---disabling.
Unsupported modifier, resource creation failed.
Unsupported modifier, resource creation failed.
Unsupported modifier, resource creation failed.
Unsupported modifier, resource creation failed.
Unsupported modifier, resource creation failed.

My guess is the suggested fix is part of the issue. I get this feeling I open another bug and there is a dependency with this issue. Should we not try to debug here instead of just addressing the shader log messages?

If not, then what should I capture (debugging and all) to make sure we get everything for the investigator in one shot?

Trust me, this is a complete unrelated issue (that I do not have). Please do not SPAM this issue with unrelated topic.

I've continued the separate issue with this bug filed 23 days ago:

https://bugzilla.mozilla.org/show_bug.cgi?id=1933040

I see this too, after invoking firefox (via pwsh, in warp):

(org.mozilla.firefox:20680): Gtk-WARNING **: 13:15:55.798: Failed to export handle, could not set transient for
libva info: VA-API version 1.22.0
libva info: Trying to open /usr/lib64/dri-nonfree/radeonsi_drv_video.so
libva info: Trying to open /usr/lib64/dri-freeworld/radeonsi_drv_video.so
libva info: Found init function __vaDriverInit_1_22
Failed to create /home for shader cache (Permission denied)---disabling.
libva info: va_openDriver() returns 0
Failed to create /home for shader cache (Permission denied)---disabling.
Failed to create /home for shader cache (Permission denied)---disabling.
Failed to create /home for shader cache (Permission denied)---disabling.
Failed to create /home for shader cache (Permission denied)---disabling.
Failed to create /home for shader cache (Permission denied)---disabling.
Failed to create /home for shader cache (Permission denied)---disabling.
Failed to create /home for shader cache (Permission denied)---disabling.
Failed to create /home for shader cache (Permission denied)---disabling.
Failed to create /home for shader cache (Permission denied)---disabling.

My environment information is available at show_bug.cgi?id=1945022#c2.

(In reply to benjarobin from comment #29)

(In reply to rsramkis from comment #27)

But I am still seeing the journal filling up with the same error messages.

From a terminal, is the environment variable MESA_SHADER_CACHE_DIR set? What is the output of: echo $MESA_SHADER_CACHE_DIR
If the environment variable MESA_SHADER_CACHE_DIR is indeed set, close all Firefox window / process, then launch Firefox from that terminal. Do you have still these errors messages, and if this is the case, what is the error exactly?

I just realized I also have this problem. I set MESA_SHADER_CACHE_DIR to ~/.cache (according to the changes you made to the documentation on the MR, it seems Mesa will look for $MESA_SHADER_CACHE_DIR/mesa_shader_cache_db, which does exist), but permission denied errors are still logged.

~/.cache 
❯ ls -ld mesa_shader_cache_db
drwx------. 1 costa costa 602 out 29 16:07 mesa_shader_cache_db/

~/.cache 
❯ echo $MESA_SHADER_CACHE_DIR
/home/costa/.cache

~/.cache 
❯ firefox 
[ERROR glean_core::metrics::ping] Invalid reason code active for ping usage-reporting
Failed to create /home for shader cache (Permission denied)---disabling.
Failed to create /home for shader cache (Permission denied)---disabling.
Failed to create /home for shader cache (Permission denied)---disabling.
Failed to create /home for shader cache (Permission denied)---disabling.
Failed to create /home for shader cache (Permission denied)---disabling.
Failed to create /home for shader cache (Permission denied)---disabling.
...

As far as I understand, this was expected, considering that ~/.cache/mesa_shader_cache_db/ should be the fallback dir if MESA_SHADER_CACHE_DIR is not set. Or, in other words, setting the environment var didn't have any impact, we still need a proper fix for the root-cause...

I did another test: I removed both mesa_shader_cache and mesa_shader_cache_db from ~/.cache, and restarted Firefox. The directories are automatically recreated, but the Failed to create /home for shader cache (Permission denied)---disabling are still flooding the journal. mesa_shader_cache is empty, but mesa_shader_cache_db is filled with partXX subdirectories, and .db and .idx files.

(In reply to André Costa from comment #37)

I did another test: I removed both mesa_shader_cache and mesa_shader_cache_db from ~/.cache, and restarted Firefox. The directories are automatically recreated, but the Failed to create /home for shader cache (Permission denied)---disabling are still flooding the journal. mesa_shader_cache is empty, but mesa_shader_cache_db is filled with partXX subdirectories, and .db and .idx files.

I just realized this had already been tested on comment #10, sorry for the oversight.

According to comment #23, the code that prints the error message is pretty straightforward; it the path it received is indeed /home, it should of course fail. So, we need to understand why mkdir_if_needed() is receiving /home as argument in the first place, and if this failure is relevant for hardware acceleration (it seems to be).

(BTW it would be great if this issue could be marked as CONFIRMED 😉)

@André Costa I think most of what you said is wrong. Please double check what the code is doing. With my fix in mesa, the log should no longer be displayed, but it just hide the Firefox bug (Firefox most likely wants shader cache, but it cannot create it since in a very restrictive "container").

And for the code, you read it wrong. Here the call trace that generates this warning:

  • disk_cache_create()
  • disk_cache_delete_old_cache()
  • disk_cache_generate_cache_dir(ctx, NULL, NULL, DISK_CACHE_MULTI_FILE)
  • concatenate_and_mkdir(mem_ctx, "/home/user/.cache", "mesa_shader_cache")
  • mkdir_with_parents_if_needed("/home/user/.cache/mesa_shader_cache")
  • mkdir_if_needed("/home")
  • stat("/home")

Hi @benjarobin, you're probably right, this was a superficial analysis on my part. And thanks for providing the call stack. Still, I believe we can agree on two points:

  • the proposed Mesa MR just avoids log spamming if disk_cache_enabled() returns false (which I can't say if it is the case when Firefox is trying to play videos with HW accel), but regardless the root-cause still remains on Firefox
  • mkdir_if_needed() is receiving /home as the argument

Assuming the logic on this version of disk_cache.c is still valid, mkdir_if_needed() should return 0 if the directory already exists or is successfully created. It passes the stat() call on line 145, because the error is logged on line 159.

The if below is failing

int ret = mkdir(path, 0755);
   if (ret == 0 || (ret == -1 && errno == EEXIST))
     return 0;

because the attempt to create /home fails and errno is EACCESS -- which is right considering no user process should be able to create /home. So, again, the point is: should mkdir_if_needed() receive /home as argument? Maybe it should receive instead /home/<user> and check for write access before failing and returning -1 ?

(In reply to André Costa from comment #40)

  • mkdir_if_needed() is receiving /home as the argument

Yes

It passes the stat() call on line 145, because the error is logged on line 159.

Wrong! We do not reach the mkdir call. The stat fails with EACCESS.
Where did you see the line number?
Personally I checked it by adding printf trace to mesa code. And I assure you that this is the stat call that fail.

I guess we're both right. stat() call is failing, and mkdir() is being called. Check this link, it shows the line numbers, and the implementation for mkdir_if_needed():

/* Create a directory named 'path' if it does not already exist.
 *
 * Returns: 0 if path already exists as a directory or if created.
 *         -1 in all other cases.
 */
static int
mkdir_if_needed(const char *path)
{
   struct stat sb;

   /* If the path exists already, then our work is done if it's a
    * directory, but it's an error if it is not.
    */
   if (stat(path, &sb) == 0) {
      if (S_ISDIR(sb.st_mode)) {
         return 0;
      } else {
         fprintf(stderr, "Cannot use %s for shader cache (not a directory)"
                         "---disabling.\n", path);
         return -1;
      }
   }

   int ret = mkdir(path, 0755);
   if (ret == 0 || (ret == -1 && errno == EEXIST))
     return 0;

   fprintf(stderr, "Failed to create %s for shader cache (%s)---disabling.\n",
           path, strerror(errno));

   return -1;
}

This is line 145:

   if (stat(path, &sb) == 0) {

and these are lines 155-160:

   int ret = mkdir(path, 0755);
   if (ret == 0 || (ret == -1 && errno == EEXIST))
     return 0;

   fprintf(stderr, "Failed to create %s for shader cache (%s)---disabling.\n",
           path, strerror(errno));

The log message which spams the logs is recorded on line 159, so there is no doubt we're reaching it. But, in order to reach this line, stat() call failed (returned != 0), and the very first line after the if around the stat() call is the mkdir().

IMHO it doesn't make sense to call mkdir() if stat() failed with EACCESS (actually probably with any code != ENOENT ?), the code should be adapted to handle this. Still, this would fix the logic, but not the problem at hand.

My C coding days are loooooooong gone, but as far as I can see, If stat() failed with EACCESS it meant search permission is denied for one of the directories of the path. Since we're talking about /home (which should be "searchable" by any regular user), could Firefox sandbox be the one to blame?

So... should we file a separate issue to tackle the root-cause? I understand the error spamming will probably be fixed in Mesa, but it will not fix the fact that Firefox should be able to create the cache structure it needs (in fact, the directory already exists and is writable to the user), but it fails to do it due to different permissions problems (directory traversal and intermediate directory creation).

Just filed bug 1947617

I'm going to dupe this to bug 1947617 because it became clear there that this is really a Mesa bug where it tries to manipulate the shader cache even if it is disabled (which it is for sandboxing reasons and because we don't need it). Fixed in Mesa 25.0.0.

Status: UNCONFIRMED → RESOLVED
Closed: 1 year ago
Duplicate of bug: 1947617
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: