zsh slow and hogs cpu when using */*/*.ext on large file tree

zsh slow and hogs cpu when using */*/*.ext on large file tree

[KARBOWSKI Piotr]

Hello,

I've come a cross issue with zsh where using the */*/*.ebuild on 
Gentoo's portage tree take about 20 secounds and hogs 100% of single CPU 
core before it builds the list of files to act on.

Something like `grep foo */*/*.ebuild` does not even start the grep for 
20 seconds.

Running `find . -maxdepth 3 -name \*.ebuild` or running `grep foo 
*/*/*.ebuild` under bash does not seems to suffer from the same issue.

The system is rather powerful and the storage is on ssd thus I believe 
the issue is within zsh and not the hardware.

-- Piotr.

Re: zsh slow and hogs cpu when using */*/*.ext on large file tree

[Sebastian Gniazdowski]

What version of Zsh? 5.2 has optimizations that could help. Could you
compare speeds?

Best regards,
Sebastian Gniazdowski

Re: zsh slow and hogs cpu when using */*/*.ext on large file tree

[KARBOWSKI Piotr]

Hello,

On 12/11/2015 10:46 PM, Sebastian Gniazdowski wrote:
> What version of Zsh? 5.2 has optimizations that could help. Could you
> compare speeds?

That was 5.1.1, update to 5.2 and it seems to be faster, but still many 
times slower than bash.


# time zsh -c 'cd /usr/portage && ls */*/*.ebuild >/dev/null'
zsh -c 'cd /usr/portage && ls */*/*.ebuild >/dev/null'  2.36s user 0.13s 
system 99% cpu 2.493 total

# time bash -c 'cd /usr/portage && ls */*/*.ebuild >/dev/null'
bash -c 'cd /usr/portage && ls */*/*.ebuild >/dev/null'  0.12s user 
0.11s system 98% cpu 0.236 total

-- Piotr.

Re: zsh slow and hogs cpu when using */*/*.ext on large file tree

[Sebastian Gniazdowski]

On 12 December 2015 at 17:06, KARBOWSKI Piotr <piotr.karbowski@gmail.com> wrote:
> Hello,
>
> On 12/11/2015 10:46 PM, Sebastian Gniazdowski wrote:
>>
>> What version of Zsh? 5.2 has optimizations that could help. Could you
>> compare speeds?
>
>
> That was 5.1.1, update to 5.2 and it seems to be faster, but still many
> times slower than bash.
>
>
> # time zsh -c 'cd /usr/portage && ls */*/*.ebuild >/dev/null'
> zsh -c 'cd /usr/portage && ls */*/*.ebuild >/dev/null'  2.36s user 0.13s
> system 99% cpu 2.493 total


So it's step from ~20s to 2.493? Very nice, not that I'm neglecting
your opinion about how this compares to Bash

Best Regards,
Sebastian Gniazdowski

Re: zsh slow and hogs cpu when using */*/*.ext on large file tree

[Sebastian Gniazdowski]

PS. I wonder if operating system didn't cache the work that zsh has
done. In other words, in such situation, every following run of */*/*
will be fast. That's why I couldn't test this on my machine (which is
OS X) and I asked you to test.

If you are somehow able to overcome operating system optimizations
(i.e. e.g. every run of */*/* on 5.1.1 is 20 seconds long) then the
values you gave are reliable and usable. Otherwise, bash my benefit
from zsh run.

Best regards,
Sebastian Gniazdowski

Re: zsh slow and hogs cpu when using */*/*.ext on large file tree

[Piotr Karbowski]

Hi,

On 12/12/2015 05:33 PM, Sebastian Gniazdowski wrote:
 > PS. I wonder if operating system didn't cache the work that zsh has
 > done. In other words, in such situation, every following run of */*/*
 > will be fast. That's why I couldn't test this on my machine (which is
 > OS X) and I asked you to test.
 >
 > If you are somehow able to overcome operating system optimizations
 > (i.e. e.g. every run of */*/* on 5.1.1 is 20 seconds long) then the
 > values you gave are reliable and usable. Otherwise, bash my benefit
 > from zsh run.

Actually it does not seems that 5.1.1 is much slower than 5.2. My report 
was wrong as the grep did not showed up for 20s as with first X files it 
wasn't finding anyting, here I've tested with ls.

But anyways, if I drop the VFS caches with `echo 3 > 
/proc/sys/vm/drop_caches` before every test, the zsh 5.2 takes 5.546s 
and bash 4.3.42 takes 3.295 thus we can presume that the VFS layer on 
ext4 filesystem I run here takes about 3.0s, rest is within the userspace.

-- Piotr.

Re: zsh slow and hogs cpu when using */*/*.ext on large file tree

[Sebastian Gniazdowski]

On 12 December 2015 at 17:43, Piotr Karbowski <jabberuser@gmail.com> wrote:
> ...
> Actually it does not seems that 5.1.1 is much slower than 5.2. My report was
> wrong as the grep did not showed up for 20s as with first X files it wasn't
> finding anyting, here I've tested with ls.
>
> But anyways, if I drop the VFS caches with `echo 3 >
> /proc/sys/vm/drop_caches` before every test, the zsh 5.2 takes 5.546s and
> bash 4.3.42 takes 3.295 thus we can presume that the VFS layer on ext4
> filesystem I run here takes about 3.0s, rest is within the userspace.

I understand what you mean. With VSF optimizations Zsh was 5.546 - 3 =
~2.5, bash was 3.295 - 3 = 0.295.

Could you provide such result for 5.1.1? With VFS warmed up and
dropped, fresh? It's important for me as I worked on Zsh optimizations
recently, with Bart who did all of the code.

Best regards,
Sebastian Gniazdowski

Re: zsh slow and hogs cpu when using */*/*.ext on large file tree

[Sebastian Gniazdowski]

I theoretically can drop caches on OS X with "purge" command, but ls
/*/*/*/*.h is still faster than the cold run. So I did only warm
tests:

zsh-5.0.8        0.749s
zsh-5.2           0,742s
bash-3.2         0.179s

It seems that OS X caches everything even after "purge" and I cannot
do meaningful tests like yours, but still, these are my results.

Best regards,
Sebastian Gniazdowski

Re: zsh slow and hogs cpu when using */*/*.ext on large file tree

[Bart Schaefer]

On Dec 12,  5:43pm, Piotr Karbowski wrote:
}
} Actually it does not seems that 5.1.1 is much slower than 5.2. My report 
} was wrong as the grep did not showed up for 20s as with first X files it 
} wasn't finding anyting, here I've tested with ls.

To get an accurate reading of the time spent by the shell itself, you
should compare a command that generates the list of files and then
throws it away; e.g.

    time zsh -fc '/bin/true */*/*.ebuild'

There's really no way to get timings of the glob without also adding
the shell startup time, so this may be a little off (hence -f to try
to skip as much startup as possible).

To make the zsh time output look like bash's,

    TIMEFMT=$'real\t%E\nuser\t%U\nsys\t%S'

There are a whole lot of other possible values you can put in TIMEFMT in
zsh to get more details about where it might be taking extra.