rharish101 / ReGreet

Clean and customizable greeter for greetd
GNU General Public License v3.0
375 stars 17 forks source link

regreet takes long to render #9

Closed natsukashiixo closed 1 year ago

natsukashiixo commented 1 year ago

It takes about 30 seconds for the GUI to show up after the service has launched on my laptop. (I get a grey background with a cursor at first. I assume this is because the greetd.service has started) APU: AMD A9-9410 RADEON R5 Graphics Driver: amdgpu OS: Arch Linux

Output from /var/log/regreet/log while starting the system using regreet -l debug:

2023-02-26T20:57:19.188404032+01:00 DEBUG regreet::sysutil: UID_MIN: 1000, UID_MAX: 60000
2023-02-26T20:57:19.188544989+01:00 DEBUG regreet::sysutil: Found user 'ntsu' with UID '1000' and empty full name
2023-02-26T20:57:19.190002503+01:00  INFO regreet::sysutil: Now scanning session file: /usr/share/wayland-sessions/hyprland.desktop
2023-02-26T20:57:19.190370256+01:00 DEBUG regreet::sysutil: Found name 'Hyprland' for session: /usr/share/wayland-sessions/hyprland.desktop
2023-02-26T20:57:19.19039119+01:00  INFO regreet::sysutil: Now scanning session file: /usr/share/wayland-sessions/sway.desktop
2023-02-26T20:57:19.190676391+01:00 DEBUG regreet::sysutil: Found name 'Sway' for session: /usr/share/wayland-sessions/sway.desktop
2023-02-26T20:57:19.190690944+01:00  INFO regreet::sysutil: Now scanning session file: /usr/share/wayland-sessions/wrapped_hl.desktop
2023-02-26T20:57:19.19093545+01:00  WARN regreet::sysutil: No command found for session: /usr/share/wayland-sessions/wrapped_hl.desktop
2023-02-26T20:57:19.192229248+01:00  INFO regreet::tomlutils: Loaded TOML file: /var/cache/regreet/cache.toml
2023-02-26T20:57:19.192518015+01:00  INFO regreet::tomlutils: Loaded TOML file: /etc/greetd/regreet.toml
2023-02-26T20:57:20.226968811+01:00  INFO regreet::client: Cancelling greetd session
2023-02-26T20:57:20.227171083+01:00 DEBUG regreet::gui::component: Setting dark theme: true
2023-02-26T20:57:20.251379389+01:00 DEBUG regreet::gui::component: Setting cursor theme: Nordic
2023-02-26T20:57:20.251760545+01:00 DEBUG regreet::gui::component: Setting font: Arimo 16
2023-02-26T20:57:20.252324492+01:00 DEBUG regreet::gui::component: Setting icon theme: Nordic
2023-02-26T20:57:20.257631131+01:00 DEBUG regreet::gui::component: Setting theme: Nordic
2023-02-26T20:57:20.307192019+01:00 DEBUG regreet::gui::component: Found user: ntsu
2023-02-26T20:57:20.307996086+01:00 DEBUG regreet::gui::component: Found session: Hyprland
2023-02-26T20:57:20.308256877+01:00 DEBUG regreet::gui::component: Found session: Sway
2023-02-26T20:57:20.313769223+01:00 DEBUG update_with_view{input=UserChanged(UserSessInfo { user_id: Some("ntsu"), user_text: "", sess_id: None, sess_text: "" }) component="regreet::gui::model::Greeter" id="0x7ffc0902baf0"}:user_change_handler: regreet::gui::model: Retrieved username 'ntsu' from options
2023-02-26T20:57:30.719530197+01:00 DEBUG update_with_view{input=Login { info: UserSessInfo { user_id: Some("ntsu"), user_text: "", sess_id: Some("Hyprland"), sess_text: "" } } component="regreet::gui::model::Greeter" id="0x7ffc0902baf0"}:login_click_handler: regreet::gui::model: Retrieved username 'ntsu' from options
2023-02-26T20:57:30.719560157+01:00  INFO update_with_view{input=Login { info: UserSessInfo { user_id: Some("ntsu"), user_text: "", sess_id: Some("Hyprland"), sess_text: "" } } component="regreet::gui::model::Greeter" id="0x7ffc0902baf0"}:login_click_handler: regreet::gui::model: Creating session for user: ntsu
2023-02-26T20:57:30.719565904+01:00  INFO update_with_view{input=Login { info: UserSessInfo { user_id: Some("ntsu"), user_text: "", sess_id: Some("Hyprland"), sess_text: "" } } component="regreet::gui::model::Greeter" id="0x7ffc0902baf0"}:login_click_handler: regreet::client: Creating session for username: ntsu
2023-02-26T20:57:34.289736854+01:00  INFO update_with_view{input=Login { info: UserSessInfo { user_id: Some("ntsu"), user_text: "", sess_id: Some("Hyprland"), sess_text: "" } } component="regreet::gui::model::Greeter" id="0x7ffc0902baf0"}:login_click_handler: regreet::client: Sending password to greetd
2023-02-26T20:57:34.295012606+01:00  INFO update_with_view{input=Login { info: UserSessInfo { user_id: Some("ntsu"), user_text: "", sess_id: Some("Hyprland"), sess_text: "" } } component="regreet::gui::model::Greeter" id="0x7ffc0902baf0"}:login_click_handler: regreet::gui::model: Successfully logged in; starting session
2023-02-26T20:57:34.295048406+01:00 DEBUG update_with_view{input=Login { info: UserSessInfo { user_id: Some("ntsu"), user_text: "", sess_id: Some("Hyprland"), sess_text: "" } } component="regreet::gui::model::Greeter" id="0x7ffc0902baf0"}:login_click_handler: regreet::gui::model: Retrieved current session: Hyprland
2023-02-26T20:57:34.295060524+01:00  INFO update_with_view{input=Login { info: UserSessInfo { user_id: Some("ntsu"), user_text: "", sess_id: Some("Hyprland"), sess_text: "" } } component="regreet::gui::model::Greeter" id="0x7ffc0902baf0"}:login_click_handler: regreet::client: Starting greetd session with command: ["Hyprland"]
2023-02-26T20:57:34.295183635+01:00  INFO update_with_view{input=Login { info: UserSessInfo { user_id: Some("ntsu"), user_text: "", sess_id: Some("Hyprland"), sess_text: "" } } component="regreet::gui::model::Greeter" id="0x7ffc0902baf0"}:login_click_handler: regreet::gui::model: Session successfully started
2023-02-26T20:57:34.295191984+01:00 DEBUG update_with_view{input=Login { info: UserSessInfo { user_id: Some("ntsu"), user_text: "", sess_id: Some("Hyprland"), sess_text: "" } } component="regreet::gui::model::Greeter" id="0x7ffc0902baf0"}:login_click_handler: regreet::gui::model: Retrieved username 'ntsu' from options
2023-02-26T20:57:34.295199385+01:00 DEBUG update_with_view{input=Login { info: UserSessInfo { user_id: Some("ntsu"), user_text: "", sess_id: Some("Hyprland"), sess_text: "" } } component="regreet::gui::model::Greeter" id="0x7ffc0902baf0"}:login_click_handler: regreet::gui::model: Updated cache with current user: ntsu
2023-02-26T20:57:34.295203765+01:00  INFO update_with_view{input=Login { info: UserSessInfo { user_id: Some("ntsu"), user_text: "", sess_id: Some("Hyprland"), sess_text: "" } } component="regreet::gui::model::Greeter" id="0x7ffc0902baf0"}:login_click_handler: regreet::gui::model: Saving cache to disk
2023-02-26T20:57:34.295218879+01:00  INFO update_with_view{input=Login { info: UserSessInfo { user_id: Some("ntsu"), user_text: "", sess_id: Some("Hyprland"), sess_text: "" } } component="regreet::gui::model::Greeter" id="0x7ffc0902baf0"}:login_click_handler: regreet::cache: Saving cache to disk
rharish101 commented 1 year ago

That's strange. The logs don't show a 30s gap anywhere. Further, the first log line should be printed before the GUI is rendered, which is the bottleneck on my system (takes about 3s for rendering, and it's on my laptop from 2016). So perhaps there's something else that's preventing ReGreet from starting up fast, like the Wayland compositor. Could you post your greetd and compositor configs?

natsukashiixo commented 1 year ago

Its pretty puzzling to me as well because systemd-analyze blame doesn't return anything that takes over 1s to load and I have no idea how to debug further.

I don't have a user configuration for sway (I double checked ~/.config/ and sway didn't have a folder) so this is from /etc/sway/config.

I also merged my separate config files and added comments for separation, I don't know if this is bad practice, it just felt like it made sense to do so.

##/etc/sway/config starts here:

# Default config for sway
#
# Copy this to ~/.config/sway/config and edit it to your liking.
#
# Read `man 5 sway` for a complete reference.

### Variables
#
# Logo key. Use Mod1 for Alt.
set $mod Mod4
# Home row direction keys, like vim
set $left h
set $down j
set $up k
set $right l
# Your preferred terminal emulator
set $term foot
# Your preferred application launcher
# Note: pass the final command to swaymsg so that the resulting window can be opened
# on the original workspace that the command was run on.
set $menu dmenu_path | dmenu | xargs swaymsg exec --

### Output configuration
#
# Default wallpaper (more resolutions are available in /usr/share/backgrounds/sway/)
output * bg /usr/share/backgrounds/sway/Sway_Wallpaper_Blue_1920x1080.png fill
#
# Example configuration:
#
#   output HDMI-A-1 resolution 1920x1080 position 1920,0
#
# You can get the names of your outputs by running: swaymsg -t get_outputs

### Idle configuration
#
# Example configuration:
#
# exec swayidle -w \
#          timeout 300 'swaylock -f -c 000000' \
#          timeout 600 'swaymsg "output * power off"' resume 'swaymsg "output * power on"' \
#          before-sleep 'swaylock -f -c 000000'
#
# This will lock your screen after 300 seconds of inactivity, then turn off
# your displays after another 300 seconds, and turn your screens back on when
# resumed. It will also lock your screen before your computer goes to sleep.

### Input configuration
#
# Example configuration:
#
#   input "2:14:SynPS/2_Synaptics_TouchPad" {
#       dwt enabled
#       tap enabled
#       natural_scroll enabled
#       middle_emulation enabled
#   }
#
# You can get the names of your inputs by running: swaymsg -t get_inputs
# Read `man 5 sway-input` for more information about this section.

### Key bindings
#
# Basics:
#
    # Start a terminal
    bindsym $mod+Return exec $term

    # Kill focused window
    bindsym $mod+Shift+q kill

    # Start your launcher
    bindsym $mod+d exec $menu

    # Drag floating windows by holding down $mod and left mouse button.
    # Resize them with right mouse button + $mod.
    # Despite the name, also works for non-floating windows.
    # Change normal to inverse to use left mouse button for resizing and right
    # mouse button for dragging.
    floating_modifier $mod normal

    # Reload the configuration file
    bindsym $mod+Shift+c reload

    # Exit sway (logs you out of your Wayland session)
    bindsym $mod+Shift+e exec swaynag -t warning -m 'You pressed the exit shortcut. Do you really want to exit sway? This will end your Wayland session.' -B 'Yes, exit sway' 'swaymsg exit'
#
# Moving around:
#
    # Move your focus around
    bindsym $mod+$left focus left
    bindsym $mod+$down focus down
    bindsym $mod+$up focus up
    bindsym $mod+$right focus right
    # Or use $mod+[up|down|left|right]
    bindsym $mod+Left focus left
    bindsym $mod+Down focus down
    bindsym $mod+Up focus up
    bindsym $mod+Right focus right

    # Move the focused window with the same, but add Shift
    bindsym $mod+Shift+$left move left
    bindsym $mod+Shift+$down move down
    bindsym $mod+Shift+$up move up
    bindsym $mod+Shift+$right move right
    # Ditto, with arrow keys
    bindsym $mod+Shift+Left move left
    bindsym $mod+Shift+Down move down
    bindsym $mod+Shift+Up move up
    bindsym $mod+Shift+Right move right
#
# Workspaces:
#
    # Switch to workspace
    bindsym $mod+1 workspace number 1
    bindsym $mod+2 workspace number 2
    bindsym $mod+3 workspace number 3
    bindsym $mod+4 workspace number 4
    bindsym $mod+5 workspace number 5
    bindsym $mod+6 workspace number 6
    bindsym $mod+7 workspace number 7
    bindsym $mod+8 workspace number 8
    bindsym $mod+9 workspace number 9
    bindsym $mod+0 workspace number 10
    # Move focused container to workspace
    bindsym $mod+Shift+1 move container to workspace number 1
    bindsym $mod+Shift+2 move container to workspace number 2
    bindsym $mod+Shift+3 move container to workspace number 3
    bindsym $mod+Shift+4 move container to workspace number 4
    bindsym $mod+Shift+5 move container to workspace number 5
    bindsym $mod+Shift+6 move container to workspace number 6
    bindsym $mod+Shift+7 move container to workspace number 7
    bindsym $mod+Shift+8 move container to workspace number 8
    bindsym $mod+Shift+9 move container to workspace number 9
    bindsym $mod+Shift+0 move container to workspace number 10
    # Note: workspaces can have any name you want, not just numbers.
    # We just use 1-10 as the default.
#
# Layout stuff:
#
    # You can "split" the current object of your focus with
    # $mod+b or $mod+v, for horizontal and vertical splits
    # respectively.
    bindsym $mod+b splith
    bindsym $mod+v splitv

    # Switch the current container between different layout styles
    bindsym $mod+s layout stacking
    bindsym $mod+w layout tabbed
    bindsym $mod+e layout toggle split

    # Make the current focus fullscreen
    bindsym $mod+f fullscreen

    # Toggle the current focus between tiling and floating mode
    bindsym $mod+Shift+space floating toggle

    # Swap focus between the tiling area and the floating area
    bindsym $mod+space focus mode_toggle

    # Move focus to the parent container
    bindsym $mod+a focus parent
#
# Scratchpad:
#
    # Sway has a "scratchpad", which is a bag of holding for windows.
    # You can send windows there and get them back later.

    # Move the currently focused window to the scratchpad
    bindsym $mod+Shift+minus move scratchpad

    # Show the next scratchpad window or hide the focused scratchpad window.
    # If there are multiple scratchpad windows, this command cycles through them.
    bindsym $mod+minus scratchpad show
#
# Resizing containers:
#
mode "resize" {
    # left will shrink the containers width
    # right will grow the containers width
    # up will shrink the containers height
    # down will grow the containers height
    bindsym $left resize shrink width 10px
    bindsym $down resize grow height 10px
    bindsym $up resize shrink height 10px
    bindsym $right resize grow width 10px

    # Ditto, with arrow keys
    bindsym Left resize shrink width 10px
    bindsym Down resize grow height 10px
    bindsym Up resize shrink height 10px
    bindsym Right resize grow width 10px

    # Return to default mode
    bindsym Return mode "default"
    bindsym Escape mode "default"
}
bindsym $mod+r mode "resize"

#
# Status Bar:
#
# Read `man 5 sway-bar` for more information about this section.
bar {
    position top

    # When the status_command prints a new line to stdout, swaybar updates.
    # The default just shows the current date and time.
    status_command while date +'%Y-%m-%d %I:%M:%S %p'; do sleep 1; done

    colors {
        statusline #ffffff
        background #323232
        inactive_workspace #32323200 #32323200 #5c5c5c
    }
}

include /etc/sway/config.d/*

##/etc/sway/config.d/50-systemd-user.conf starts here

# sway does not set DISPLAY/WAYLAND_DISPLAY in the systemd user environment
# See FS#63021
# Adapted from xorg's 50-systemd-user.sh, which achieves a similar goal.

exec systemctl --user import-environment DISPLAY WAYLAND_DISPLAY SWAYSOCK XDG_CURRENT_DESKTOP
exec hash dbus-update-activation-environment 2>/dev/null && \
     dbus-update-activation-environment --systemd DISPLAY WAYLAND_DISPLAY SWAYSOCK XDG_CURRENT_DESKTOP

from greetr configs:

##/etc/greetd/config.toml starts here

[terminal]
# The VT to run the greeter on. Can be "next", "current" or a number
# designating the VT.
vt = 1

# The default session, also known as the greeter.
[default_session]

# `agreety` is the bundled agetty/login-lookalike. You can replace `/bin/sh`
# with whatever you want started, such as `sway`.
command = "sway --config /etc/greetd/sway-config"

# The user to run the command as. The privileges this user must have depends
# on the greeter. A graphical greeter may for example require the user to be
# in the `video` group.
user = "greeter"

##/etc/greetd/sway-config starts here

exec "regreet -l debug; swaymsg exit"
include /etc/sway/config.d/*

##/etc/greetd/regreet.toml starts here

# SPDX-FileCopyrightText: 2022 Harish Rajagopal <harish.rajagopals@gmail.com>
#
# SPDX-License-Identifier: GPL-3.0-or-later

# Path to the background image
background = "/home/ntsu/Pictures/syoko19201080.jpg"

# How the background image covers the screen if the aspect ratio doesn't match
# Available values: "Fill", "Contain", "Cover", "ScaleDown"
# Refer to: https://docs.gtk.org/gtk4/enum.ContentFit.html
# NOTE: This is ignored if ReGreet isn't compiled with GTK v4.8 support.
background_fit = "Fill"

# The entries defined in this section will be passed to the session as environment variables when it is started
[env]
ENV_VARIABLE = "value"

[GTK]
# Whether to use the dark theme
application_prefer_dark_theme = true

# Cursor theme name
cursor_theme_name = "Nordic"

# Font name and size
font_name = "Arimo 16"

# Icon theme name
icon_theme_name = "Nordic"

# GTK theme name
theme_name = "Nordic"
rharish101 commented 1 year ago

Your configs look fine. /etc/sway/config shouldn't be used, so it's unnecessary.

Could you describe the point where ReGreet hangs (or takes 30s to load)? Is it at the screen where the background is grey and you see the cursor (that's when Sway is open but ReGreet hasn't started yet)?

Also, how much time does gtkgreet take to load with a similar greetd and Sway config?

For debugging further, a good way is to profile the code. Try something like flamegraph with ReGreet in debug mode (you would need a working Rust installation for debug mode). Once you get a flamegraph, could you post it here? I have no experience profiling code, but I'll give it a shot!

natsukashiixo commented 1 year ago

Yeah. It hangs at the grey screen with a cursor. (I have a few seconds of a tty that only shows an _ character as well but I believe that's unrelated because that's probably just something that's stopping the initial greeter daemon from starting, so I'll have to troubleshoot that later.)

trying to run regreet from my terminal returns:

ERROR: Couldn't create log file '/var/log/regreet/log': Permission denied (os error 13)
thread 'main' panicked at 'Couldn't initialize greetd client: 0s { code: 13, kind: PermissionDenied, message: "Permission denied" }', src/gui/model.rs:7847
note: run with 'RUST_BACKTRACE=1' environment variable to display a backtrace

trying to run it using sudo returns:

Authorization required, but no authorization protocol specified

thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: BoolError { message: "Failed to initialize GTK", filename: "/home/ntsu/.cargo/registry/src/github.com-1ecc6299db9ec823/gtk4-0.5.5/src/rt.rs", function: "gtk4::rt", line: 153 }', /home/ntsu/.cargo/registry/src/github.com-1ecc6299db9ec823/relm4-0.5.0/src/lib.rs:110:17
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

To generate the logs last time I edited my config to execute regreet with -l debug. Am I supposed to change permissions and run it from CLI, or should I run further tests as I've done previously where I fully restart?

As for gtkgreet and flamegraph I'll most likely have to get back to you tomorrow with their results

rharish101 commented 1 year ago

Ah, for the authorization error, you need to run a command to allow running GTK apps as root. As per the Arch wiki, you need to run:

xhost si:localuser:root

Normally you need to run the greeter as the user greeter (sudo -u greeter), but flamegraph needs root. Hence, just run it as root.

Yeah. It hangs at the grey screen with a cursor.

So it's probably waiting to start the binary, since the logs don't indicate a large waiting time for rendering. Please try gtkgreet and see if it takes time as well.

natsukashiixo commented 1 year ago

I can't get it to launch from CLI even when I add myself to xhost so I'm going the reboot route, editing /etc/greetd/sway-config as needed. Anyways, using gtkgreet it only took a few seconds for the GUI to appear. I still get the grey screen with a cursor so that isn't instant either but that's fine. So I guess this confirms that it's something that regreet is struggling with.

I'll try editing /etc/greetd/sway-config to exec flamegraph [-o ~/regreetlog.svg] -- regreet -l debug; swaymsg exit though I guess it might fail since it would run under the user greeter instead of as root. (I'm also not sure the syntax is right, but hopefully it is)

Update/edit: oops I messed something up : D It can't find flamegraph which I guess is because my machine doesn't run this as ZSH but as Bash and I haven't set up the path to cargo in bash. I might also have forgotten a # somewhere because the error log says "Unknown/invalid command 'Uncomment'". Anyways, I can probably fix this myself, just writing it out because of posterity and because I think its funny.

natsukashiixo commented 1 year ago

I hate to be that guy but its suddenly much faster even with the default config. No idea why. I didn't manage to get flamegraph to generate the .svg file but I have perf.data and perf.data.old that I could possibly upload if that helps?

rharish101 commented 1 year ago

I hate to be that guy but its suddenly much faster even with the default config. No idea why.

IMG-20230228-WA0000

Anyway, if it seems to be working fine regularly, feel free to close the issue.

I didn't manage to get flamegraph to generate the .svg file but I have perf.data and perf.data.old that I could possibly upload if that helps?

Hmm, maybe I can try and see if flamegraph can generate the svg with the perf files.

natsukashiixo commented 1 year ago

perf.data.gz perf.data.old.gz I'll keep the issue open for a while longer in case you find something in these logs

rharish101 commented 1 year ago

Here are the flamegraphs:

From perf.data: flamegraph

From perf.data.old: flamegraph old

You can download these flamegraphs and open them separately to interact with them. Opening them using "Open link/image in new tab" doesn't work though.

Is perf.data after ReGreet was fixed, or before? Because in perf.data.old I see very long wait times due to LLVM and RadeonSI (AMD's OpenGL driver). That could explain the insane wait times for you.

In perf.data, RadeonSI is still taking some time, but it's a lot less (relative to GTK, which I'm assuming takes about the same time). The bottleneck now is mostly GTK, which is expected.

natsukashiixo commented 1 year ago

Is perf.data after ReGreet was fixed, or before? Because in perf.data.old I see very long wait times due to LLVM and RadeonSI (AMD's OpenGL driver). That could explain the insane wait times for you.

Perf.data should be after it was fixed yeah. Perf.data.old is the relevant one. No idea why LLVM is doing stuff at boot, its a compiler isn't it? Makes sense that issues with the graphics driver would cause the long render time though. I haven't updated my system so the fix wasn't something as simple as doing a driver update. I wonder how it performs with other AMD drivers

rharish101 commented 1 year ago

No idea why LLVM is doing stuff at boot, its a compiler isn't it?

Yes, but it also provides some libraries that compiled programs can use at runtime. I'm assuming that ReGreet is relying on this, and for some reason it's taking a lot of time to do it's job.

Makes sense that issues with the graphics driver would cause the long render time though.

Oh well, at least we found out that the graphics drivers can cause issues like this. Maybe if someone else comes across this issue, they can update their drivers (and LLVM) first and then check if this still happens.

Anyway, since we figured out that it wasn't an issue with ReGreet, I'm going to go ahead and close this issue.

VioletRoses commented 1 year ago

This is an old issue but it seems this has to do with xdg-desktop-portal not activating correctly. I had the same issue and this post from the Sway wiki helped me (Could be a good idea to reference it in the README?)

https://github.com/swaywm/sway/wiki#gtk-applications-take-20-seconds-to-start

natsukashiixo commented 1 year ago

This is an old issue but it seems this has to do with xdg-desktop-portal not activating correctly. I had the same issue and this post from the Sway wiki helped me (Could be a good idea to reference it in the README?)

https://github.com/swaywm/sway/wiki#gtk-applications-take-20-seconds-to-start

This seems to have been the issue for me as well since I followed this and I now consistently get into regreet faster. Thank you!

rharish101 commented 1 year ago

This is an old issue but it seems this has to do with xdg-desktop-portal not activating correctly. I had the same issue and this post from the Sway wiki helped me (Could be a good idea to reference it in the README?)

https://github.com/swaywm/sway/wiki#gtk-applications-take-20-seconds-to-start

Thanks for the link! Apparently Arch already includes this in the default Sway configs (at /etc/sway/config.d/50-systemd-user.conf), so I'll add this to the recommended Sway config in the README.