You are not logged in.
Hello,
I am running powershell-bin from AUR, the current version 7.3.1. I find that it is extremely slow to launch the interactive shell and to launch powershell scripts. For example, I have to wait minutes before getting the powershell ready:
$ pwsh -l
PowerShell 7.1.3
Copyright (c) Microsoft Corporation.
https://aka.ms/powershell
Type 'help' to get help.
After I wait some minutes, I finally get the input line:
PS /home/user>
PS /home/user>
PS /home/user>
Anyone with a similar problem? Do you know how to debug this issue?
Thanks,
Christian
Last edited by chrpinedo (2021-05-04 10:41:01)
Offline
I'm not sure about powershell from aur but on windows 10 it's much slower than e.g. bash, especially if you are using a mechanical hard drive like me
Offline
I use SSD. I think it is not a hardware performance problem but a software failure DNS resolution, some checks... However, I don't know how to check or debug it.
Offline
Powershell *is* slow as fuck.
What makes you believe it's a DNS issue? Is PS faster w/o a network connection?
Offline
it is only one idea... Because when I launch pwsh my CPU is idle, pwsh process is not using heavily the CPU and the iostat is quite low also. So it seems more a timeout, lock or something similar.
Offline
You could strace it and use wireshark to see whether it generates any traffic (or tcpdump/ss)
Offline
In one PC, in which it runs slowly, it takes 51 seconds!
0.000021 madvise(0x7fdc6428e000, 4096, MADV_DODUMP) = 0
0.000256 stat("/opt/microsoft/powershell/7/profile.ps1", 0x7ffdb62b5460) = -1 ENOENT (No such file or directory)
0.000033 lstat("/opt/microsoft/powershell/7/profile.ps1", 0x7ffdb62b5470) = -1 ENOENT (No such file or directory)
0.000023 stat("/opt/microsoft/powershell/7/Microsoft.PowerShell_profile.ps1", 0x7ffdb62b5460) = -1 ENOENT (No such file or directory)
0.000020 lstat("/opt/microsoft/powershell/7/Microsoft.PowerShell_profile.ps1", 0x7ffdb62b5470) = -1 ENOENT (No such file or directory)
0.000021 stat("/home/bcppizac/.config/powershell/profile.ps1", 0x7ffdb62b5460) = -1 ENOENT (No such file or directory)
0.000021 lstat("/home/bcppizac/.config/powershell/profile.ps1", 0x7ffdb62b5470) = -1 ENOENT (No such file or directory)
0.000019 stat("/home/bcppizac/.config/powershell/Microsoft.PowerShell_profile.ps1", 0x7ffdb62b5460) = -1 ENOENT (No such file or directory)
0.000018 lstat("/home/bcppizac/.config/powershell/Microsoft.PowerShell_profile.ps1", 0x7ffdb62b5470) = -1 ENOENT (No such file or directory)
0.000199 mprotect(0x7fdc6428f000, 4096, PROT_READ|PROT_WRITE) = 0
0.000019 madvise(0x7fdc6428f000, 4096, MADV_DODUMP) = 0
0.000172 mprotect(0x7fdc642a0000, 4096, PROT_READ|PROT_WRITE) = 0
0.000023 madvise(0x7fdc642a0000, 4096, MADV_DODUMP) = 0
0.000341 ioctl(0, SNDCTL_TMR_START or TCSETS, {B38400 opost isig -icanon -echo ...}) = 0
0.000042 write(1, "\33[6n", 4) = 4
0.000038 mprotect(0x7fdc64199000, 4096, PROT_READ|PROT_WRITE) = 0
0.000022 madvise(0x7fdc64199000, 4096, MADV_DODUMP) = 0
0.000017 mprotect(0x7fdc64199000, 4096, PROT_READ|PROT_WRITE|PROT_EXEC) = 0
0.000023 read(0, "\33", 1) = 1
0.027391 read(0, "[", 1) = 1
0.000317 read(0, "8", 1) = 1
0.000283 read(0, "6", 1) = 1
0.000096 read(0, ";", 1) = 1
0.000022 read(0, "3", 1) = 1
0.000191 read(0, "5", 1) = 1
0.000028 read(0, "R", 1) = 1
0.000146 write(52, "\n", 1
) = 1
0.000247 ioctl(1, TIOCGWINSZ, {ws_row=86, ws_col=159, ws_xpixel=956, ws_ypixel=1041}) = 0
0.000193 mprotect(0x7fdc64296000, 4096, PROT_READ|PROT_WRITE) = 0
0.000080 madvise(0x7fdc64296000, 4096, MADV_DODUMP) = 0
0.000097 mprotect(0x7fdc642a1000, 4096, PROT_READ|PROT_WRITE) = 0
0.000024 madvise(0x7fdc642a1000, 4096, MADV_DODUMP) = 0
0.000140 futex(0x562d7d5a6760, FUTEX_WAKE_PRIVATE, 1) = 1
0.000020 futex(0x562d7d5a6710, FUTEX_WAKE_PRIVATE, 1) = 1
0.000024 futex(0x562d7d42c3c0, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY) = 0
0.018958 futex(0x562d7d42c370, FUTEX_WAKE_PRIVATE, 1) = 0
0.000408 write(52, "PS /home/bcppizac> ", 19PS /home/bcppizac> ) = 19
0.000316 mprotect(0x7fdc642d5000, 4096, PROT_READ|PROT_WRITE) = 0
0.000091 madvise(0x7fdc642d5000, 4096, MADV_DODUMP) = 0
0.000209 read(47, "\201\306\356\313\373\2405f1\343\206\204\232\301:z", 16) = 16
0.000161 futex(0x562d7d5a6764, FUTEX_WAKE_PRIVATE, 1) = 1
0.000027 futex(0x562d7d5a6710, FUTEX_WAKE_PRIVATE, 1) = 1
0.000062 futexexit62d7d42c3c4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY
) = 0
51.519397 futex(0x562d7d42c370, FUTEX_WAKE_PRIVATE, 1) = 0
In another PC, it takes less than 5 sec:
0.000279 stat("/opt/microsoft/powershell/7/profile.ps1", 0x7ffefa5171a0) = -1 ENOENT (No existe el fichero o el directorio)
0.000055 lstat("/opt/microsoft/powershell/7/profile.ps1", 0x7ffefa5171b0) = -1 ENOENT (No existe el fichero o el directorio)
0.000037 stat("/opt/microsoft/powershell/7/Microsoft.PowerShell_profile.ps1", 0x7ffefa5171a0) = -1 ENOENT (No existe el fichero o el directorio)
0.000030 lstat("/opt/microsoft/powershell/7/Microsoft.PowerShell_profile.ps1", 0x7ffefa5171b0) = -1 ENOENT (No existe el fichero o el directorio)
0.000030 stat("/home/zako/.config/powershell/profile.ps1", 0x7ffefa5171a0) = -1 ENOENT (No existe el fichero o el directorio)
0.000031 lstat("/home/zako/.config/powershell/profile.ps1", 0x7ffefa5171b0) = -1 ENOENT (No existe el fichero o el directorio)
0.000031 stat("/home/zako/.config/powershell/Microsoft.PowerShell_profile.ps1", 0x7ffefa5171a0) = -1 ENOENT (No existe el fichero o el directorio)
0.000029 lstat("/home/zako/.config/powershell/Microsoft.PowerShell_profile.ps1", 0x7ffefa5171b0) = -1 ENOENT (No existe el fichero o el directorio)
0.000620 mprotect(0x7f6ee5b82000, 4096, PROT_READ|PROT_WRITE) = 0
0.000049 madvise(0x7f6ee5b82000, 4096, MADV_DODUMP) = 0
0.000255 mprotect(0x7f6ee5b83000, 4096, PROT_READ|PROT_WRITE) = 0
0.000035 madvise(0x7f6ee5b83000, 4096, MADV_DODUMP) = 0
0.000111 mprotect(0x7f6ee5b74000, 4096, PROT_READ|PROT_WRITE) = 0
0.000033 madvise(0x7f6ee5b74000, 4096, MADV_DODUMP) = 0
0.000186 mprotect(0x7f6ee5a4c000, 4096, PROT_READ|PROT_WRITE) = 0
0.000068 madvise(0x7f6ee5a4c000, 4096, MADV_DODUMP) = 0
0.000043 mprotect(0x7f6ee5a4c000, 4096, PROT_READ|PROT_WRITE|PROT_EXEC) = 0
0.000062 mprotect(0x7f6ea87b0000, 65536, PROT_READ|PROT_WRITE) = 0
0.000028 madvise(0x7f6ea87b0000, 65536, MADV_DODUMP) = 0
0.000139 mprotect(0x7f6ee5b84000, 4096, PROT_READ|PROT_WRITE) = 0
0.000029 madvise(0x7f6ee5b84000, 4096, MADV_DODUMP) = 0
0.000271 mprotect(0x7f6ee5b85000, 4096, PROT_READ|PROT_WRITE) = 0
0.000031 madvise(0x7f6ee5b85000, 4096, MADV_DODUMP) = 0
0.000347 mprotect(0x7f6ee5b86000, 4096, PROT_READ|PROT_WRITE) = 0
0.000251 madvise(0x7f6ee5b86000, 4096, MADV_DODUMP) = 0
0.002383 ioctl(0, SNDCTL_TMR_START or TCSETS, {B38400 opost isig -icanon -echo ...}) = 0
0.000106 write(1, "\33[6n", 4) = 4
0.000065 read(0, "\33", 1) = 1
0.000037 read(0, "[", 1) = 1
0.000034 read(0, "4", 1) = 1
0.000027 read(0, "2", 1) = 1
0.000028 read(0, ";", 1) = 1
0.000026 read(0, "3", 1) = 1
0.000026 read(0, "5", 1) = 1
0.000029 read(0, "R", 1) = 1
0.000655 write(52, "\n", 1
) = 1
0.000275 ioctl(1, TIOCGWINSZ, {ws_row=42, ws_col=159, ws_xpixel=956, ws_ypixel=511}) = 0
0.000273 mprotect(0x7f6ee5b87000, 4096, PROT_READ|PROT_WRITE) = 0
0.000042 madvise(0x7f6ee5b87000, 4096, MADV_DODUMP) = 0
0.000064 mprotect(0x7f6ee5b75000, 4096, PROT_READ|PROT_WRITE) = 0
0.000068 madvise(0x7f6ee5b75000, 4096, MADV_DODUMP) = 0
0.000246 futex(0x55750fe427e0, FUTEX_WAKE_PRIVATE, 1) = 1
0.000049 futex(0x55750fc1cdf4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY) = 0
0.035012 futex(0x55750fc1cda0, FUTEX_WAKE_PRIVATE, 1) = 0
0.000364 write(52, "PS /home/zako> ", 15PS /home/zako> ) = 15
0.000352 read(47, "E\377\265H\205F{\23\266\233,\234\244\325Y\203", 16) = 16
0.000442 futex(0x55750fe427e4, FUTEX_WAKE_PRIVATE, 1) = 1
0.000069 futex(0x55750fe42790, FUTEX_WAKE_PRIVATE, 1) = 1
0.000192 fexit(0x55750fc1cdf0, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY
) = 0
4.861583 futex(0x55750fc1cda0, FUTEX_WAKE_PRIVATE, 1) = 0
It is not a configuration problem. I removed the local configuration (.local/share/powershell) and cache (~/.cache/powershell), and it continues slow.
Regards,
Offline
Please don't copy and paste out of the terminal.
Use "strace -tf powershell > /tmp/powershell.strace 2>&1" and post that file (for the slow one) but this just seems to wait for some fexit (but the uaddr isn't listed before)
Offline
@seth I create this temporary share with the output of your command: https://ehubox.ehu.eus/s/TQx7iDYnmaSBRXk
(I think it is not possible to share files in this forum)
Offline
It takes ~1 second to get to
[pid 690661] 16:06:50 write(52, "PowerShell 7.1.3\nCopyright (c) M"..., 106PowerShell 7.1.3
Copyright (c) Microsoft Corporation.
https://aka.ms/powershell
Type 'help' to get help.
) = 106
[pid 690661] 16:06:50 write(52, "\n", 1
) = 1
[pid 690677] 16:06:50 sendto(44, "<134>May 3 16:06:50 powershell["..., 205, MSG_NOSIGNAL, NULL, 0) = 205
Same second, looks like a prompt…
[pid 690678] 16:06:50 statfs("/automount/usbdisk", <unfinished ...>
One wonders what it's doing there…
Most of the time threads just seem to wait for each other - or IO
How long did it actually take to start this?
Also: what desktop environment/display server (might be more a problem w/ seeing the window than starting PS)
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 getrandom("\xb3\x3e\xa2\x37\x3b\xae\xa6\x59\x11\xa4\x04\x4c\xeb\x6d\xc0\x7e\x3e\x72\x81\xb9\x89\x27\x9f\xaa\x9a\xa8\x64\x31\xb1\x0c\xeb\x8a", 32, 0) = 32
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 futex(0x7fc18e76a938, FUTEX_WAKE_PRIVATE, 2147483647) = 0
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 mprotect(0x7fc1700dc000, 4096, PROT_READ|PROT_WRITE) = 0
[pid 690739] 16:07:20 mprotect(0x7fc1700dd000, 8192, PROT_READ|PROT_WRITE) = 0
[pid 690739] 16:07:20 mprotect(0x7fc1e3ab7000, 4096, PROT_READ|PROT_WRITE) = 0
[pid 690739] 16:07:20 madvise(0x7fc1e3ab7000, 4096, MADV_DODUMP) = 0
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 getpid() = 690661
[pid 690739] 16:07:20 getpid() = 690661
What's my pid?
Really?
Really?
Really?
Really?
…
mickeysoft…
Offline
So, trash and more tash, let's hope future versions will improve performance.... Thank you for your analysis @seth
Last edited by chrpinedo (2021-05-04 06:40:40)
Offline
How long did it actually take to start this?
Also: what desktop environment/display server (might be more a problem w/ seeing the window than starting PS)
What kinda baffles me is that the help message shows up within a second - if it takes 51 for you to see the powershell window, there might be something else, eg. about mapping the window or just seeing it in the compositor.
Offline
Great!! You found the key!!
I have defined systemd automount filesystems in /etc/fstab. It seems that powershell, when it starts, is forcing the mount of all of these autmount filesystems and it waits for them to be mounted. I reduce x-systemd.device-timeout to 2 seconds and now at least pwsh boots in 5-10 seconds!
Thanks for your analysis.
Offline
That explains the many mountpoint accesses…
Please always remember to mark resolved threads by editing your initial posts subject - so others will know that there's no task left, but maybe a solution to find.
Thanks.
Offline