varietywalls / variety

Wallpaper downloader and manager for Linux systems
http://peterlevi.com/variety
GNU General Public License v3.0
1.2k stars 146 forks source link

Variety causes gnome to keep file handles open #561

Open dolfandringa opened 2 years ago

dolfandringa commented 2 years ago

Version of Variety 0.8.9 on Fedora Workstation 36 with Gnome 42.4 with Xorg.

Describe the bug When run variety, for some reason two timerfd file handles are opened in gnome, every time variety runs through a cycle of code. I initially filed a bug report with gnome, because I didn't know what was causing it, and gnome is keeping the file handles open. But since I filed that report, I discovered it only happens while I am running variety. When I stop variety, the file handles stop increasing, and then when I start variety, more file handles get opened constantly. So it pretty clearly is related to the combination of variety and gnome. But where, I am not sure.

Specifically, what I noticed is that gnome-shell crashes because it has too many file handles open (above the single-process soft limit). When checking the open file handles on gnome with lsof -p $(pidof gnome-shell), I see steadily increasing number of a_inode [timerfd] file handles getting opened by gnome. The number never decreases and only increases. I used a small python script to monitor this (see the gnome bug report because I can't attach it here).

As I said, as soon as I stop variety, the number stops increasing, and when I start variety, it starts going up again.

When starting variety with -v from the terminal, it turns out, the number exactly increases by 2, every time the cycle of functions is executed in the output below. So it looks like when that code runs, 2 file handles are opened. As far as I understand it, the timerfd file handles are timers acting through file descriptors, using anonymous inodes. Not really sure about the details, but just a rough guess, could there by a python timer thread that gets started but never stopped on each cycle? It's still weird the file-handle is opened by gnome, not variety itself though. So it maybe is something that variety is triggering on gnome? But clearly 2 handles get opened by gnome on every cycle of variety.

Attach Variety's log file

INFO: 2022-08-24 17:52:00,393: clock_thread_method() 'clock_thread updates wallpaper'
INFO: 2022-08-24 17:52:00,393: do_set_wp() 'Calling do_set_wp with /home/dolfandringa/.config/variety/Downloaded/Bing/OHR.MentonFrance_EN-US3424001829_1920x1080.jpg, time: 1661334720.3937745'
INFO: 2022-08-24 17:52:00,394: apply_auto_rotate() 'ImageMagick auto-rotate cmd: convert /home/dolfandringa/.config/variety/Downloaded/Bing/OHR.MentonFrance_EN-US3424001829_1920x1080.jpg -auto-orient /home/dolfandringa/.config/variety/wallpaper/wallpaper-auto-rotated-65a3792edcb51c7171b9d68ff8f3dda4.jpg'
INFO: 2022-08-24 17:52:00,440: apply_display_mode() 'ImageMagick display mode cmd: convert /home/dolfandringa/.config/variety/wallpaper/wallpaper-auto-rotated-65a3792edcb51c7171b9d68ff8f3dda4.jpg -scale 3440x1440^  /home/dolfandringa/.config/variety/wallpaper/wallpaper-zoomed-d3397fb2c953f6f1403cdc758b182456.jpg'
INFO: 2022-08-24 17:52:00,665: compute_trimmed_offsets() 'Trimmed offsets debug info: w:3440, h:1440, ratio:2.388889, iw:3440, ih:1935, scw:3440, sch:1935, ho:0, vo:247'
INFO: 2022-08-24 17:52:00,665: build_imagemagick_clock_cmd() 'Applying clock filter: -density 100 -font `fc-match -f '%{file[0]}' 'Ubuntu Condensed:,:70'` -pointsize 70 -gravity SouthEast -fill '#00000044' -annotate 0x0+58+355 '17:52' -fill white -annotate 0x0+60+357 '17:52' -font `fc-match -f '%{file[0]}' 'Ubuntu Condensed:,:30'` -pointsize 30 -fill '#00000044' -annotate 0x0+58+305 'Wednesday, August 24' -fill white -annotate 0x0+60+307 'Wednesday, August 24''
INFO: 2022-08-24 17:52:00,665: build_imagemagick_clock_cmd() 'ImageMagick clock cmd: convert /home/dolfandringa/.config/variety/wallpaper/wallpaper-zoomed-d3397fb2c953f6f1403cdc758b182456.jpg -scale 3440x1440^ -density 100 -font `fc-match -f '%{file[0]}' 'Ubuntu Condensed:,:70'` -pointsize 70 -gravity SouthEast -fill '#00000044' -annotate 0x0+58+355 '17:52' -fill white -annotate 0x0+60+357 '17:52' -font `fc-match -f '%{file[0]}' 'Ubuntu Condensed:,:30'` -pointsize 30 -fill '#00000044' -annotate 0x0+58+305 'Wednesday, August 24' -fill white -annotate 0x0+60+307 'Wednesday, August 24' /home/dolfandringa/.config/variety/wallpaper/wallpaper-clock-48869ee036b46406e73c1812a5e897e4.jpg'
INFO: 2022-08-24 17:52:00,831: update_indicator() 'Setting file info to: /home/dolfandringa/.config/variety/Downloaded/Bing/OHR.MentonFrance_EN-US3424001829_1920x1080.jpg'
INFO: 2022-08-24 17:52:00,832: list_files() 'More than 1 files in the folders, stop listing'

Desktop environment and version Gnome 42.4 with Xorg.

OS name and version Fedora Workstation 36

Attached files variety.log

Can't attach my config, so here it is pasted:

# change_on_start = <True or False>
change_on_start = False

# change_enabled = <True or False>
change_enabled = True

# change_interval = <interval in seconds - not less than 5>
change_interval = 1800

# safe_mode = <True or False>
safe_mode = False

# download_folder = <some folder> - when not specified, the default is ~/.config/variety/Downloaded
download_folder = ~/.config/variety/Downloaded

# download_preference_ratio - if we have "unconsumed" download sources, we'll prefer to show a newly
# downloades image instead of an existing one in this percentage of the cases
download_preference_ratio = 0.9

# Determine if the download folder sould not exceed a certain size (in megabytes)
# quota_enabled = <True or False>
# quota_size = <size in MB, minimum 50>
quota_enabled = True
quota_size = 1000

# favorites_folder = <some folder> - when not specified, the default is ~/.config/variety/Favorites
favorites_folder = ~/.config/variety/Favorites

# Prefer Copy to Favorites or Move to Favorites operation (or both), depending on the folder of the current image
# favorites_operations = <A list of directories and the preferred operation (Copy, Move or Both) for each of them>
# The default is: Downloaded:Copy;Fetched:Move;Others:Copy
# Order is important - the first matching entry will determine what operation(s) to show in the menu for a specific file
# Special folder names you can use: Downloaded, Fetched and Others (same as "/" - use it as last entry to determine the default operation)
# Example1: Downloaded:Copy;Fetched:Move;/pics/RandomImages:Move;/pics/OrganizedAlbums:Copy;Others:Copy
# Example2: Others:Both - always show both Copy and Move to Favorites, no matter which image is shown
# Move to Favorites is only shown when the user has write permissions over the file, otherwise we fallback to Copy
favorites_operations = Downloaded:Copy;Fetched:Move;Others:Copy

# fetch_folder = <some folder> - when not specified, the default is ~/.config/variety/Fetched
fetched_folder = ~/.config/variety/Fetched

# Clipboard monitoring settings
# clipboard_enabled = <True or False>
# clipboard_use_whitelist = <will we use a hosts whitelist, or we'll fetch from everywhere - True or False>
# clipboard_hosts = <comma-separated whitelist of hosts for which clipboard fetching is enabled>
clipboard_enabled = False
clipboard_use_whitelist = True
clipboard_hosts = "wallhaven.cc,wallpapers.net,flickr.com,imgur.com,deviantart.com,interfacelift.com,vladstudio.com,imageshack.us,deviantart.net,imageshack.com"

# Icon settings
# icon = <Light, Dark, Current, 1, 2, 3, 4, None, or a full path to an image file>
icon = Light

# Prefer only images with this color:
# desired_color_enabled = <True or False>
# desired_color = <None or rgb like this: 100 150 200>
# DISCLAIMER: This feature is still experimental
desired_color_enabled = False
desired_color = 160 160 160

# Minimum size of images to use, as a percentage of the screen resolution
# min_size_enabled = <True or False>
# min_size = <Percentage>
min_size_enabled = False
min_size = 80

# Should we use only landscape-oriented images?
# use_landscape_enabled = <True or False>
use_landscape_enabled = True

# Prefer light or dark images
# lightness_enabled = <True or False>
# lightness_mode = <0 for Dark, 1 for Light>
lightness_enabled = False
lightness_mode = 0

# Use a filter by rating?
# min_rating_enabled = <True or False>
# min_rating = <1 | 2 | 3 | 4 | 5>
min_rating_enabled = False
min_rating = 4

# What parts of the initial wizard have we covered
smart_notice_shown = False
smart_register_shown = False
stats_notice_shown = False

# Are smart features enabled (i.e. data collection on Fav/Trash operations), also sync, and anonymous usage stats collection?
# smart_enabled = <True or False>
smart_enabled = False
sync_enabled = True
stats_enabled = True

# Folder to copy the wallpaper image to and make it world-readable. Provides LightDM support.
# copyto_enabled = <True or False>, default is False
# copyto_folder = <Default or Path to a custom folder>, the default is Default
# Default means to use the XDG Pictures folder when home folder is unencrypted and /usr/share/backgrounds when it is encrypted.
copyto_enabled = False
copyto_folder = Default

# Clock settings
# clock_enabled = <True or False>
# clock_font = <FontName Size>, default is "Ubuntu Condensed, 70"
# clock_date_font = <FontName Size>, default is "Ubuntu Condensed, 30"
clock_enabled = True
clock_font = "Ubuntu Condensed, 70"
clock_date_font = "Ubuntu Condensed, 30"

# clock_filter = <an ImageMagick filter, read below>
#
# The filter defines the ImageMagick command that Variety uses to render the clock on the wallpaper.
# First some scaling is applied to get the image down to the screen size - this ensures
# the final drawn clock won't be rescaled by the desktop wallpaper system.
# Easiest way to see what's happening is to run variety with -v, enable clock and see what ImageMagick
# commands Variety dumps in the log.
#
# The user may want to customize the following aspects:
# fill - color of "filling"
# stroke - color of outline
# strokewidth - width of outline
# gravity - in which corner to display the clock - SouthEast, NorthEast, SouthWest, NorthWest
# annotate - these must be in the form 0x0+[%HOFFSET+X]+[%VOFFSET+Y], where you can edit X and Y -
# distance from the screen corner defined by gravity. Write them in even if they are 0.
#
# The %HOFFSET and %VOFFSET parameters are there for Variety to replace in order to compensate for the
# diferent dimensions of every image and screen.
# The several %FONT parameters are there for Variety to replace with the font settings from the GUI.
#
# The texts can contain these symbols:
#
# %H - hours (24), %I - zero-padded hours (12), %l - hours (12), %p - am or pm, %M - minutes,
# %A - day of week (full), %a - day of week abbreviation, %B - month name, %b - month abbreviation, %d - day of month, %Y - year.
# The full list for these can be seen here: http://docs.python.org/library/datetime.html#strftime-strptime-behavior
# Have in mind that Variety will not update the clock more often than once every minute, so using seconds (%S) for example is pointless
#
# A tutorial on "annotating" with ImageMagick that you may use as a reference: http://www.imagemagick.org/Usage/annotating/
# You can get a very uniquely looking clock with some of the more advanced techniques (e.g. circle-shaped text, interesting colors and shading, etc....).

clock_filter = "-density 100 -font `fc-match -f '%{file[0]}' '%CLOCK_FONT_NAME'` -pointsize %CLOCK_FONT_SIZE -gravity SouthEast -fill '#00000044' -annotate 0x0+[%HOFFSET+58]+[%VOFFSET+108] '%H:%M' -fill white -annotate 0x0+[%HOFFSET+60]+[%VOFFSET+110] '%H:%M' -font `fc-match -f '%{file[0]}' '%DATE_FONT_NAME'` -pointsize %DATE_FONT_SIZE -fill '#00000044' -annotate 0x0+[%HOFFSET+58]+[%VOFFSET+58] '%A, %B %d' -fill white -annotate 0x0+[%HOFFSET+60]+[%VOFFSET+60] '%A, %B %d'"

# Quotes settings
# quotes_enabled = <True or False>
# quotes_font = <FontName Size>, default is Bitstream Charter 30
# quotes_text_color = <r g b>, default is 255 255 255
# quotes_bg_color = <r g b>, default is 80 80 80
# quotes_bg_opacity = <0-100>, default is 55
# quotes_width = <0-100>, default is 70
# quotes_hpos = <0-100>, default is 100
# quotes_vpos = <0-100>, default is 40
# quotes_max_length = a positive integer, quotes above this length will not be displayed
# (as they often won't fit well on screen)
# quotes_text_shadow = <True or False>, default is False
# quotes_disabled_sources = <|-separated list of disabled quote plugin names>, default is "Urban Dictionary"
# quotes_tags = <comma-separated list of tags>, default is empty
# quotes_authors = <comma-separated list of authors>, default is empty
# quotes_change_enabled = <True or False>
# quotes_change_interval = <interval in seconds - not less than 10>, default is 300
quotes_enabled = False
quotes_font = Bitstream Charter 30
quotes_text_color = 255 255 255
quotes_bg_color = 80 80 80
quotes_bg_opacity = 55
quotes_text_shadow = False
quotes_width = 70
quotes_hpos = 100
quotes_vpos = 40
quotes_max_length = 250
quotes_disabled_sources = Urban Dictionary
quotes_tags = ""
quotes_authors = ""
quotes_change_enabled = False
quotes_change_interval = 300
quotes_favorites_file = ~/.config/variety/favorite_quotes.txt
quotes_favorites_format = fortune

# Slideshow settings
slideshow_favorites_enabled = True
slideshow_sources_enabled = True
slideshow_downloads_enabled = False
slideshow_custom_enabled = False
slideshow_custom_folder = /home/dolfandringa
slideshow_sort_order = Random
slideshow_monitor = All
slideshow_mode = Fullscreen
slideshow_seconds = 6.0
slideshow_fade = 0.4
slideshow_zoom = 0.2
slideshow_pan = 0.05
internet_enabled = True
set_wallpaper_script = ~/.config/variety/scripts/set_wallpaper
get_wallpaper_script = ~/.config/variety/scripts/get_wallpaper
wallhaven_api_key = ""
wallpaper_auto_rotate = True
wallpaper_display_mode = zoom

# List of sources
# Each source is srcX = <enabled or not|source type - one of image, folder, flickr, wallhaven, etc.|location>
# location depends on type - path or url or search options, or just a name for unconfigurable sources
# Folders are included recursively
# BE CAREFUL: all keys below (src1, src2, etc.) MUST be different
[sources]
src1 = True|favorites|The Favorites folder
src2 = True|fetched|The Fetched folder
src3 = False|folder|/usr/share/backgrounds
src4 = False|flickr|user:www.flickr.com/photos/peter-levi/;user_id:93647178@N00;
src5 = True|apod|NASA's Astronomy Picture of the Day
src6 = True|bing|Bing Photo of the Day
src7 = True|earthview|Google Earth View Wallpapers
src8 = False|unsplash|High-resolution photos from Unsplash.com
src9 = True|unsplash-search|https://unsplash.com/s/photos/nature
src10 = False|natgeo|National Geographic's photo of the day
src11 = True|chromeos|Chrome OS Wallpapers
src12 = False|desktoppr|Random wallpapers from Desktoppr.co

# Image filters to apply randomly to every wallpaper (ImageMagick is used for this)
# Each filter is filterX = <enabled or not|filter name|arguments to pass to ImageMagick when calling convert>
# BE CAREFUL: all keys below (filter1, filter2, etc.) MUST be different
[filters]
filter1 = False|Keep original|
filter2 = False|Grayscale|-type Grayscale
filter3 = False|Heavy blur|-scale 20% -blur 0x10 -resize 500%
filter4 = False|Soft blur|-scale 20% -blur 0x2 -resize 500%
filter5 = False|Oil painting|-paint 8
filter6 = False|Pointilism|-spread 10 -noise 3
filter7 = False|Pixellate|-scale 3% -scale 3333%

Thank you. -->

dolfandringa commented 2 years ago

Ok, I did a little more digging. Adding a return at the start of update_indicator and update_indicator_icon didn't change anything. So its probably not the appindicator code. I also manually executed the gsettings commands from the update script, and those didn't trigger it either. BUt I do see this code:

def set_wp_throttled(self, filename, refresh_level=RefreshLevel.ALL):
        if not filename:
            logger.warning(lambda: "set_wp_throttled: No wallpaper to set")
            return

        self.thumbs_manager.mark_active(file=filename, position=self.position)

        def _do_set_wp():
            self.do_set_wp(filename, refresh_level)

        threading.Timer(0, _do_set_wp).start()

which gets called from refresh_clock which itself gets called from clock_thread_method. Do I see correctly that the set_wp_throttled method starts a new thread on every cycle? And that thread is part of the GTK window? So could it be that the thread timer is therefore part of the window object, which python or GTKor gnome implements using a timerfd inode, which then shows up on the UI as part of gnome? And could it be that the timer is started, but the thread never stopped?

dolfandringa commented 2 years ago

I did boil it down to the section below. If I use args = [script, wallpaper, auto, original_file, display_mode], the file handles get opened every time it gets called, but if I change it to args = ["echo","hi there"], the file handles don't get opened by gnome.

But I also tried calling just

import subprocess
args = ['/home/dolfandringa/.config/variety/scripts/set_wallpaper', '/home/dolfandringa/.config/variety/wallpaper/wallpaper-zoomed-f919fcf586e2d3637307e77a12246118.jpg','manual','/home/dolfandringa/.config/variety/Downloaded/Bing/OHR.MentonFrance_EN-US3424001829_1920x1080.jpg','os']
subprocess.check_call(args, timeout=10)

from a python cli, and then the file handles don't get opened in gnome. So it does have to do something with the combination GTK, Gnome, Python, subprocess and the script itself.

 def set_desktop_wallpaper(self, wallpaper, original_file, refresh_level, display_mode):
        script = self.options.set_wallpaper_script
        if os.access(script, os.X_OK):
            auto = (
                "manual"
                if not self.auto_changed
                else ("auto" if refresh_level == VarietyWindow.RefreshLevel.ALL else "refresh")
            )
            logger.debug(
                lambda: "Running set_wallpaper script %s with parameters: %s, %s, %s, %s"
                % (script, wallpaper, auto, original_file, display_mode)
            )
            try:
                args = [script, wallpaper, auto, original_file, display_mode]
                # args = ["echo","hi there"]
                subprocess.check_call(
                    args , timeout=10
                )
            except subprocess.TimeoutExpired:
                logger.error(lambda: "Timeout while running set_wallpaper script, killed")
            except subprocess.CalledProcessError as e:
                logger.exception(
                    lambda: "Exception when calling set_wallpaper script: %d" % e.returncode
                )
        else:
            logger.error(lambda: "set_wallpaper script is missing or not executable: " + script)
            if self.gsettings:
                self.gsettings.set_string("picture-uri", "file://" + wallpaper)
                self.gsettings.apply()
dolfandringa commented 2 years ago

Ok, I did manage to boil it all the way down. It has nothing to do with threading, Python, GTK, timers or variety. It can be boiled down to changing the background through gsettings. See https://gitlab.gnome.org/GNOME/gnome-shell/-/issues/5796#note_1537208.

Be aware that variety does cause my desktop to crash as a result, so the only temporary fix I have is not use variety, but it's not a code issue in variety at all.

dolfandringa commented 2 years ago

@jlu5 thanks for adding those tags. I agree. The only thing I think on variety could be done (not taking time availability into account) is restrict the number of gsettings calls as much as possible, and maybe limit the update frequency of the desktop background. Its not a solution to the real problem, but a workaround that may make variety not as likely to trigger the issue. I think the number of gsettings calls is quite high, and as a result, I run out of open gnome open file limit quite fast (<1 day usually). I also often leave my PC on over night, and that really increases the likelihood of a crash. Not variety's fault, but still something that could be worked around maybe.

dolfandringa commented 2 years ago

For instance, checking if the user is using dark mode first, and then only updating the background for one of them, already halves the number of gsettings calls, compared to

gsettings set org.gnome.desktop.background picture-uri "file://$WP" 2> /dev/null
gsettings set org.gnome.desktop.background picture-uri-dark "file://$WP" 2> /dev/null

And beyond those 2 calls, I feel that even though my background update frequency is 30 minutes, variety still calls the background update gsettings calls more then 2x2 an hour. Is that correct?

dolfandringa commented 2 years ago

Hmm, I have changed my variety set_wallpaper and get_wallpaper into this just to add logging to journalctl showing what is going on: variety wallpaper scripts.zip And even though i only set the refresh rate of variety to 30 minutes, it seems all these commands get run every minute anyway, even if it's not necessary:

Aug 26 11:28:01 dolfdesktop variety[142444]: gsettgs get picure-uri
Aug 26 11:28:01 dolfdesktop variety[142451]: gsettings gnome set picure-uri
Aug 26 11:28:01 dolfdesktop variety[142457]: gsettings gnome set picure-uri-dark
Aug 26 11:28:01 dolfdesktop variety[142468]: gsettings gnome get picure-options
Aug 26 11:28:01 dolfdesktop variety[142473]: gsettings gnome set screensaver picure-uri
Aug 26 11:28:01 dolfdesktop variety[142479]: gsettings gnome get screensaver picure-options
Aug 26 11:28:01 dolfdesktop variety[142487]: gsettings mate set picure-filename
Aug 26 11:28:01 dolfdesktop variety[142490]: gsettings mate get picure-options
Aug 26 11:28:01 dolfdesktop variety[142494]: gsettings cinnamon set picure-uri
Aug 26 11:28:01 dolfdesktop variety[142497]: gsettings cinnamon get picure-options

With a memory leak on gnome, no wonder I run out of open file handles fast. Shouldn't the gsettings commands not run much less then every minute?

dolfandringa commented 2 years ago

So looking at it better, normally of all those gsettings commands, only a single file handle is opened additionally. But it still means 1 filehandle a minute. If the desktop background actually changes (2x per hour), there are 2 more opened. And also, it runs the commands for cinnamon, mate and gnome. So I feel there is definitely some room for optimization to reduce the impact of the gnome open file handle issue

dolfandringa commented 2 years ago

Maybe a thought is to keep track of the previous wallpaper and options that variety set it to, and only call the set_wallpaper script if something changed, once a minute, instead of just always calling it. This could be implemented quite easily with a decorator maybe that is put around the update function in python, and keeps track of the calls to the decorated function and only runs it if the last time it was called with different arguments then are used now.

dolfandringa commented 2 years ago

Lol, I figured out why it was updating so often, I had the "clock" feature on. So the clock feature is really a bad idea on gnome, since it updates the background incredibly often, and therefore exacerbates the gnome problem tremendously.

dolfandringa commented 2 years ago

Maybe disable the clock feature on gnome, or at least display a warning or something