Open HarshNarayanJha opened 4 months ago
I have the same problem on PopOS using AMD radeon graphics
Interesting that it seems to block on the system. Could you please try again with strace -ftT
and see if we can see which calls are blocking for a while.
We had a similar bug on X11 where we'd block waiting to query for settings for multiple seconds, so hopefully we can identify the problem and remove it from the critical path.
I get something like this: log.txt
UPDATE: these are the timings just after a fresh reboot
________________________________________________________
Executed in 1.25 secs fish external
usr time 0.52 millis 521.00 micros 0.00 millis
sys time 3.48 millis 145.00 micros 3.33 millis
Running with strace produces a 18MB logfile! Do you only need certain lines of it?
It opens in about 15-20 seconds for me
@Stefano299 How did you generate that strace? it seems to be missing the first ~13 seconds of events (based on pid 5298). I think (after you've made sure there are no other instances of zed running) that running strace -ftT zed --foreground
should work, but I'm not an expert. (It may as @HarshNarayanJha says be quite a large file!).
That said, there's still some odd looking stuff in here:
/sys/bus/pci
tree. We open each device 4-5 times, and some of your PCI devices are very slow to respond (e.g. reading /sys/bus/pci/devices/0000:00:01.1/config
takes ~450ms and we do it 4 times!).Not sure exactly why yet, but it seems like at the least we should only do this once, and ideally we should not do it at all during app boot.
@HarshNarayanJha I'm looking for things that take time, or just seem off. If you don't want to upload the whole log try:
zed-editor
process (probably the one with the most stuff going on).<[1-9].
for things that take >1s, or <0.[1-9]
for 100ms or more (etc.)Thanks, I did it wrong. I found the problem, while starting it I get like infinite lines like this: [pid 7193] 07:09:16 openat(AT_FDCWD, "/sys/bus/pci/devices/0000:00:18.3/config", O_RDONLY) = 78 <0.000013> [pid 7193] 07:09:16 read(78, "\"\20|\26\0\0\0\0\0\0\0\6\0\0\200\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 48) = 48 <0.000011> [pid 7193] 07:09:16 close(78) = 0 <0.000007> [pid 7193] 07:09:16 openat(AT_FDCWD, "/sys/bus/pci/devices/0000:04:00.5/config", O_RDONLY) = 78 <0.000014> [pid 7193] 07:09:16 read(78, "\"\20\342\25\6\0\20\0`\0\200\4\20\0\200\0\0\0h\201\0\0\0\0\0\0\0\0\0\0\0\0"..., 48) = 48 <0.012762> [pid 7193] 07:09:16 close(78) = 0 <0.000062> [pid 7193] 07:09:16 openat(AT_FDCWD, "/sys/bus/pci/devices/0000:00:18.1/config", O_RDONLY) = 78 <0.000106> [pid 7193] 07:09:16 read(78, "\"\20z\26\0\0\0\0\0\0\0\6\0\0\200\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 48) = 48 <0.000096> [pid 7193] 07:09:16 close(78) = 0 <0.000050> [pid 7193] 07:09:16 openat(AT_FDCWD, "/sys/bus/pci/devices/0000:02:00.0/config", O_RDONLY) = 78 <0.000037> [pid 7193] 07:09:16 read(78, "\303\24\26\6\6\4\20\0\0\0\200\2\20\0\0\0\f\0\0\2\177\0\0\0\4\0\200\201\0\0\0\0"..., 48) = 48 <0.001217> [pid 7193] 07:09:16 close(78) = 0 <0.000008> [pid 7193] 07:09:16 openat(AT_FDCWD, "/sys/bus/pci/devices/0000:00:01.0/config", O_RDONLY) = 78 <0.000014> [pid 7193] 07:09:16 read(78, "\"\20\267\24\0\0\0\0\1\0\0\6\0\0\200\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 48) = 48 <0.000015> [pid 7193] 07:09:16 close(78) = 0 <0.000007> [pid 7193] 07:09:16 openat(AT_FDCWD, "/sys/bus/pci/devices/0000:04:00.3/config", O_RDONLY) = 78 <0.000014> [pid 7193] 07:09:16 read(78, "\"\20\35\26\7\4\20\0\0000\3\f\20\0\200\0\4\0000\201\0\0\0\0\0\0\0\0\0\0\0\0"..., 48) = 48 <0.140692> [pid 7193] 07:09:16 close(78) = 0 <0.000030> [pid 7193] 07:09:16 openat(AT_FDCWD, "/sys/bus/pci/devices/0000:00:02.3/config", O_RDONLY) = 78 <0.000065> [pid 7193] 07:09:16 read(78, "\"\20\272\24\7\4\20\0\0\0\4\6\20\0\201\0\0\0\0\0\0\0\0\0\0\2\2\0\361\1\0 "..., 48) = 48 <0.000041> [pid 7193] 07:09:16 close(78) = 0 <0.000014> [pid 7193] 07:09:16 openat(AT_FDCWD, "/sys/bus/pci/devices/0000:00:04.0/config", O_RDONLY) = 78 <0.000026> [pid 7193] 07:09:16 read(78, "\"\20\267\24\0\0\0\0\1\0\0\6\0\0\200\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 48) = 48 <0.000030> [pid 7193] 07:09:16 close(78) = 0 <0.000017> [pid 7193] 07:09:16 openat(AT_FDCWD, "/sys/bus/pci/devices/0000:00:14.3/config", O_RDONLY) = 78 <0.000021> [pid 7193] 07:09:16 read(78, "\"\20\16y\17\0 \2Q\0\1\6\0\0\200\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 48) = 48 <0.000034> [pid 7193] 07:09:16 close(78) = 0 <0.000017> [pid 7193] 07:09:16 openat(AT_FDCWD, "/sys/bus/pci/devices/0000:04:00.1/config", O_RDONLY) = 78 <0.000023> [pid 7193] 07:09:16 read(78, "\2\20@\26\6\4\20\0\0\0\3\4\20\0\200\0\0\200l\201\0\0\0\0\0\0\0\0\0\0\0\0"..., 48) = 48 <0.015009> [pid 7193] 07:09:16 close(78) = 0 <0.000089> [pid 7193] 07:09:16 openat(AT_FDCWD, "/sys/bus/pci/devices/0000:01:00.0/config", O_RDONLY) = 78 <0.000166> [pid 7193] 07:09:16 read(78, "\336\20\342%\0\0\20\0\241\0\0\3\20\0\0\0\0\0\0\200\f\0\0\0~\0\0\0\f\0\0\0"..., 48) = 48 <0.346766> [pid 7193] 07:09:16 close(78) = 0 <0.000059> [pid 7193] 07:09:16 openat(AT_FDCWD, "/sys/bus/pci/devices/0000:00:00.2/config", O_RDONLY) = 78 <0.000071>
This is what is making zed start so slow on my machine.
Does seem that way. So now the question is why :D. My suspicion is that this is coming from vulkan, but it does seem like we're probably doing this work more often than we need.
Is there any pattern of what happens before this in the logs? In the trace that you sent it looked like we were also connecting to the X server three times, though enumerating the PCI bus 4-5 times.
Feel free to just upload the log here if it's easier.
It's not that I don't want to upload that big file, but I though it may be useless for you, but in that case, I found things that take
But this output doesn't seem very informative to me 😅. So here is the full log
After the laptop is running for 1 hr or so, running zeditor
launch time averages at 6-7 seconds.
One interesting behavior I caught when running zeditor with strace strace -ftT zeditor --foreground &> /tmp/zed_strace.log
launches it much slower (maybe because of too much logging), but the theme I have in settings applies after a delay, as it launches with some light mode theme.
Here is the clip demonstrating that:
https://github.com/user-attachments/assets/88f3465b-dc43-4c4e-9be9-4a375d63be90
This is not the case with normal launches.
Does seem that way. So now the question is why :D. My suspicion is that this is coming from vulkan, but it does seem like we're probably doing this work more often than we need.
Is there any pattern of what happens before this in the logs? In the trace that you sent it looked like we were also connecting to the X server three times, though enumerating the PCI bus 4-5 times.
Feel free to just upload the log here if it's easier.
I'm sorry, I don't know how to send you the whole log.... I tried doing " > output.txt" but it didn't work. The output is too big and the beginning gets erased in the terminal window...
Does seem that way. So now the question is why :D. My suspicion is that this is coming from vulkan, but it does seem like we're probably doing this work more often than we need. Is there any pattern of what happens before this in the logs? In the trace that you sent it looked like we were also connecting to the X server three times, though enumerating the PCI bus 4-5 times. Feel free to just upload the log here if it's easier.
I'm sorry, I don't know how to send you the whole log.... I tried doing " > output.txt" but it didn't work. The output is too big and the beginning gets erased in the terminal window...
Actually, the whole output just gets logged to stdout
and stderr
, so you can't really redirect it to a file. You have to redirect both stdout
and stderr
using &> output.txt
, just as I did
strace -ftT zeditor --foreground &> /tmp/zed_strace.log
Thanks, this is the log: zed_strace.log
It looks like I had the same issue as well. Notably, this only occurred when I disabled the dedicated GPU on my hybrid-graphics laptop. Boot times are fine with the dedicated NVIDIA GPU enabled.
First, I disabled the dGPU with envycontrol:
sudo envycontrol -s integrated
Then, when running Zed, I saw the same startup issues. Here's an strace from running Zed:
Also, here's Zed.log.
Environment:
## Hardware Information:
- **Hardware Model:** Dell Inc. XPS 15 9530
- **Memory:** 32.0 GiB
- **Processor:** 13th Gen Intel® Core™ i9-13900H × 20
- **Graphics:** Intel® Graphics (RPL-P)
- **Disk Capacity:** (null)
## Software Information:
- **Firmware Version:** 1.13.0
- **OS Name:** Fedora Linux 40 (Workstation Edition)
- **OS Build:** (null)
- **OS Type:** 64-bit
- **GNOME Version:** 46
- **Windowing System:** Wayland
- **Kernel Version:** Linux 6.9.8-200.fc40.x86_64
Any updates?
It looks like I had the same issue as well. Notably, this only occurred when I disabled the dedicated GPU on my hybrid-graphics laptop. Boot times are fine with the dedicated NVIDIA GPU enabled.
To add to this in short: running my system on the iGPU (Intel) with my dGPU disabled with nvidia-utils installed (edit 1: from the arch repos) caused Zed to open in 15-20 seconds. Removing it, and Zed opens like normal. Installed the package again to double check I wasn't hallucinating and can reproduce it.
edit 2: As this is really not my area of expertise, I'm speculating and inferring somewhat. It seems to me the issue, in my instance at least, was the presence of multiple vulkan implementations (provided by vulkan-intel and nvidia-utils) where the GPU it wants to use (??) is not actually available. The Zed logs suggested it always ran on the iGPU.
Can you please tell me how to uninstall nvidia utils?
@Stefano299 apt remove nvidia-utils
I believe... you need to have the exact package name
To add to this in short: running my system on the iGPU (Intel) with my dGPU disabled with nvidia-utils installed (edit 1: from the arch repos) caused Zed to open in 15-20 seconds. Removing it, and Zed opens like normal. Installed the package again to double check I wasn't hallucinating and can reproduce it.
I can confirm this was the issue for me on Pop!_OS. I had a disabled NVIDIA GPU, was running on integrated graphics. However a boatload of NVIDIA packages were still installed on my machine. After purging them all (according to official instructions), zed launches instantly.
More specifically, a long time ago I ran this command to switch to integrated graphics:
sudo system76-power graphics integrated
and today I ran this to resolve the zed startup issue:
sudo apt purge ~nvidia
sudo apt autoremove
systemctl reboot
In my case I had installed both amdvlk
and vulkan-radeon
on Arch which caused Zed to take around 30 seconds to start. Removing amdvlk
solved the issue.
Edit: I was wrong, looks like zed was already open on the background when I tested the startup time without amdvlk
. After reboot, the startup time is the same.
I don't have amdvlk
installed, but it is still happening to me. I do have vulkan-radeon
Update: In my case the font parsing process is delaying the startup. I had the nerd-fonts
package installed on Arch which provides around 2200 fonts, when initiating zed
with RUST_LOG=debug
like this:
export RUST_LOG=debug
time zed --foreground # Wait until window appears and I instantly close the window to get the approximate startup time
These are the first lines of the log:
[2024-10-16T23:27:49-03:00 INFO zed] ========== starting zed ==========
[2024-10-16T23:27:49-03:00 DEBUG cosmic_text::font::system] Locale:
[2024-10-16T23:28:02-03:00 DEBUG cosmic_text::font::system] Parsed 2116 font faces in 13298ms.
[2024-10-16T23:28:03-03:00 WARN cosmic_text::font::system] failed to load font 'SymbolsNFM'
[2024-10-16T23:28:04-03:00 WARN cosmic_text::font::system] failed to load font 'SymbolsNFM'
...
26.48s real
2.65s user
23.61s sys
After the 13.29 seconds of loading the fonts, it takes around 10 seconds more to launch zed.
I removed the nerd-fonts
package, which left me with 216 fonts only (fc-list | wc -l
) an this is my log now:
[2024-10-16T23:30:45-03:00 INFO zed] ========== starting zed ==========
[2024-10-16T23:30:45-03:00 DEBUG cosmic_text::font::system] Locale:
[2024-10-16T23:30:45-03:00 DEBUG cosmic_text::font::system] Parsed 198 font faces in 10ms.
[2024-10-16T23:30:45-03:00 INFO zbus::connection::handshake::client] perform;
...
1.53s user
0.52s sys
I takes around 1.5 seconds to launch now.
And just to make sure it wasn't because there was a zed instance running on the background I executed a killall
and a reboot before each test.
Edit: More precisely, the fonts are loaded on crates/gpui/src/platform/linux/text_system.rs:39
which calls cosmic_text::FontSystem::new()
. gpui
is using rev 542b20c
of cosmic_text which calls FontSystem::new_with_fonts
which in turn calls Self::load_fonts(&mut db, fonts.into_iter());
this last function is causing the slow startup:
#[cfg(feature = "std")]
fn load_fonts(db: &mut fontdb::Database, fonts: impl Iterator<Item = fontdb::Source>) {
#[cfg(not(target_arch = "wasm32"))]
let now = std::time::Instant::now();
db.load_system_fonts();
for source in fonts {
db.load_font_source(source);
}
#[cfg(not(target_arch = "wasm32"))]
log::debug!(
"Parsed {} font faces in {}ms.",
db.len(),
now.elapsed().as_millis()
);
}
There's already a TODO on CosmicTextSystem::new
but only for blocking on the second call and not the first one:
// crates/gpui/src/platform/linux/text_system.rs:38
pub(crate) fn new() -> Self {
let mut font_system = FontSystem::new();
// todo(linux) make font loading non-blocking
font_system.db_mut().load_system_fonts();
...
It's also worth noting that the font_system.db_mut().load_system_fonts();
call may not be necessary because FontSystem::new()
is already calling load_system_fonts
Check for existing issues
Describe the bug / provide steps to reproduce it
Just installed the latest Zed
v0.143.6-1
from arch repos. It is considerably slow to start, taking around 10–15 seconds to launch.This behavior is the same regardless of whether I open an empty workspace or a folder.
Environment
Zed: v0.143.6 (Zed) OS: Linux Wayland garuda unknown Memory: 7.1 GiB Architecture: x86_64
Don't know why unknown is there, but I am on Arch Linux using Hyprland WM. GPU: AMD Integrated
If applicable, add mockups / screenshots to help explain present your vision of the feature
No response
If applicable, attach your Zed.log file to this issue.
Zed.log