bat is extremely slow (>100x slower than cat) for 4 char file

[desbma]

What version of bat are you using?
See output of info.sh below.

Describe the bug you encountered:

$ echo hey > /tmp/a
$ time cat /tmp/a
hey
cat /tmp/a  0,00s user 0,00s system 71% cpu 0,001 total
$ time bat /tmp/a
...
bat /tmp/a  0,14s user 0,02s system 99% cpu 0,159 total
$ time bat --plain /tmp/a
hey
bat --plain /tmp/a  0,10s user 0,00s system 98% cpu 0,105 total

Bat is ~100-150x slower than cat, even with --plain.
It may be a recent regression, because it did not notice it was that slow before.

Describe what you expected to happen?
I expect it to be as fast or only marginally slower.
I have seen #304 but this issue is not about piping thousands of lines, just a few chars, and the fact that it's that slow with --plain tells something abnormal is going on.

How did you install bat?
Official Arch package: https://www.archlinux.org/packages/community/x86_64/bat/

Here is the output of info.sh for my system:

system

$ uname -srm
Linux 5.4.32-1-lts x86_64

$ lsb_release -a
LSB Version: 1.4
Distributor ID: Arch
Description: Arch Linux
Release: rolling
Codename: n/a

bat

$ bat --version
bat 0.13.0

$ env
BAT_THEME=Solarized (dark)

$ bat --list-languages
Found custom syntax set.

$ bat --list-themes
Found custom theme set.

bat_config

bat_wrapper

No wrapper script.

bat_wrapper_function

No wrapper function.

tool

$ less --version
less 551 (PCRE regular expressions)

[sharkdp]

Thank you for the detailed report.

The problem is not the time that it takes bat to output 4 characters. The problem is the startup time. Especially since you are using a custom syntax and theme set.

Measuring the bat startup time on my machine, I get:

hyperfine --warmup 10 'echo test | bat' --export-markdown no-custom-set.md

Command	Mean [ms]	Min [ms]	Max [ms]	Relative
echo test | bat	48.2 ± 1.7	45.4	52.3	1.00

With a custom syntax/theme set, I get:

bat cache --build
hyperfine --warmup 10 'echo test | bat' --export-markdown custom-set.md

Command	Mean [ms]	Min [ms]	Max [ms]	Relative
echo test | bat	92.8 ± 1.6	90.1	96.3	1.00

Startup time of bat has always been a source of concern for me. It is the main reason why I am quite restrictive in adding new syntaxes and themes to bat. I think that a startup time of 50 milliseconds (without custom syntaxes/themes) is already on the border to being unacceptable. Startup times of 90 ms or more are definitely noticeable and annoying.

So how do we deal with this?

• First: we should improve the documentation and add a warning that custom syntaxes and themes lead to a significant slowdown in startup speed (almost factor of 2).
• As a workaround for you, you can run bat cache --clear to hopefully get back to the "old" startup speed of ~ 50 ms. If you want to keep your custom syntaxes and themes, you could try moving them to a faster filesystem (tmpfs?).
• I have done this in the past, but we should look more carefully into methods to decrease the startup speed of bat, for both cases.

Profiling a startup run of bat, we can easily see that the deserialization of the "assets" (syntaxes + themes) is the main cause of the slow startup:

I'm not sure if this is completely CPU bound, however. The bat binary is quite large, due to the fact that all syntaxes and themes are included within the binary. It might take some time to simply load that from disk (or cache).

There are several ideas that come to mind which could improve the situation:

• Somehow parallelize the deserialization process (by splitting up the binaries into smaller chunks. After all, they are made out of ~100 different syntaxes and themes)
• Only load syntaxes and themes "on demand". If syntaxes and themes were serialized separately, we might be able to load them on demand. It's probably not as easy as it sounds, because syntaxes are interlinked (code blocks in markdown files could require the loading of all kinds of syntaxes, for example).
• Try to look into ways to improve the deserialization speed.
• The assets are currently stored in compressed form. I think I have tried storing them in uncompressed form once (and didn't see any performance improvements), but it might be worth re-evaluating that.

[desbma]

Thanks for your response.

The thing is is, I have never had any custom syntax or theme set. The only customization I have is the BAT_THEME env var, and some shell aliases.

May it be related to #882 because I have files from older versions?

I have this line in my zshrc to work around the cache being older than the bat binary:
[ "$(command -v bat)" -ot ~/.cache/bat/syntaxes.bin ] && bat cache -b

[sharkdp]

The thing is is, I have never had any custom syntax or theme set.

Hm. at some point, bat cache --build must have been called in order to create these files in bat --cache-dir. Might have been from an older version, sure.

have this line in my zshrc to work around the cache being older than the bat binary:
[ "$(command -v bat)" -ot ~/.cache/bat/syntaxes.bin ] && bat cache -b

Why would you have that line in the .zshrc if you never used custom assets? If you don't have any custom syntaxes/themes, there is no reason to have that line. Or to ever call bat cache --build.

[desbma]

Why would you have that line in the .zshrc if you never used custom assets? If you don't have any custom syntaxes/themes, there is no reason to have that line. Or to ever call bat cache --build.

It seems the BAT_THEME variable is not respected until I run bat cache -b. Or is it what you call a custom theme?

Anyway if I remove ~/.cache/bat, and unset BAT_THEME, the time to show a single file is still around ~100ms on my system.

[sharkdp]

It seems the BAT_THEME variable is not respected until I run bat cache -b.

That should not be the case. The "Solarized (dark)" theme should be part of bat 0.13. How did you install bat? Could you please run bat cache --clear and then bat --list-themes to see if "Solarized (dark)" is present?

Or is it what you call a custom theme?

No. By custom theme, I mean a .tmTheme file somewhere in ~/.config/bat/themes.

Anyway if I remove ~/.cache/bat, and unset BAT_THEME, the time to show a single file is still around ~100ms on my system.

Phew... could you please post the output of info.sh after doing the steps above?

Random guess: did you maybe build bat yourself without using a release build?

[desbma]

$ bat cache --clear
Clearing theme set cache ... okay
Clearing syntax set cache ... okay
$ bat --list-themes | grep Solarized
Solarized (dark)
Solarized (light)

I can confirm the colors are not right, until I run bat cache -b again.

Random guess: did you maybe build bat yourself without using a release build?

No I'm using the official Arch Linux package.

Output of info.sh after bat cache --clear:

system
------

**$ uname -srm**
Linux 5.4.32-1-lts x86_64

**$ lsb_release -a**
LSB Version:	1.4
Distributor ID:	Arch
Description:	Arch Linux
Release:	rolling
Codename:	n/a

bat
---

**$ bat --version**
bat 0.13.0

**$ env**
BAT_THEME=Solarized (dark)

bat_config
----------

bat_wrapper
-----------

No wrapper script.

bat_wrapper_function
--------------------

No wrapper function.

tool
----

**$ less --version**
less 551 (PCRE regular expressions)

[sharkdp]

Weird. I can not reproduce this. What do you mean by "colors are not right"? Maybe you have another version of "Solarized (dark)" in bats config folder (bat --config-folder) that overwrites the builtin theme when you run bat cache --build?

[sharkdp]

Anyway if I remove ~/.cache/bat, and unset BAT_THEME, the time to show a single file is still around ~100ms on my system.

For the "4 char file"? It would be great if you could post a reproducible test case here.

If it's not too much to ask, it would be helpful to get reliable benchmark results via hyperfine:

echo "hello world" > test.txt
hyperfine \
  --warmup 10 \
  --show-output \
  --export-markdown result.md \
  'bat --no-config test.txt'

On my laptop, I get:

Command	Mean [ms]	Min [ms]	Max [ms]	Relative
bat --no-config test.txt	54.7 ± 2.7	52.2	64.6	1.00

[desbma]

Weird. I can not reproduce this. What do you mean by "colors are not right"? Maybe you have another version of "Solarized (dark)" in bats config folder (bat --config-folder) that overwrites the builtin theme when you run bat cache --build?

Yup, I had another theme file there I don't remember adding...

I will open another issue, because the current Solarized themes shipped with bat are broken and outdated.

Timings measured by hyperfine, after running bat cache --clear:

Command	Mean [ms]	Min [ms]	Max [ms]	Relative
bat --no-config test.txt	78.0 ± 17.6	50.4	96.6	1.00

Before you ask, my CPU is an Intel i7 X 990, overclocked at 4GHz. My root partition (and the bat binary) in on a SSD. Definitely not brand new, but not low end either.

[sharkdp]

I will open another issue, because the current Solarized themes shipped with bat are broken and outdated.

Ok, thanks!

Timings measured by hyperfine, after running bat cache --clear:

Thank you. These times are actually comparable with mine (min time of 50 ms), but I am assuming that you had a few other IO heavy processes running (Spotify, Dropbox, ..) which lead to a rather large standard deviation and a max time of almost 100 ms.

[sharkdp]

The situation has actually improved with the newly released bat v0.15

For custom caches, we should now see comparable startup times:

Command	Mean [ms]	Min [ms]	Max [ms]	Relative
echo test | bat	51.7 ± 1.2	49.6	55.3	1.00

This is due to a recent change by @lzutao: e37e9c1#diff-977a955f26740fd3b439f4e2f0d7aaff 👍

[desbma]

Nice, even with cache cleared, it seems to improve performance measurably on my system:

Release build at commit a482838 (one commit before the clippy fixes):

Command	Mean [ms]	Min [ms]	Max [ms]	Relative
./target/release/bat --no-config /tmp/a	77.9 ± 19.2	51.3	100.9	1.00

Release build at commit e37e9c1:

Command	Mean [ms]	Min [ms]	Max [ms]	Relative
./target/release/bat --no-config /tmp/a	69.9 ± 19.8	48.7	96.9	1.00

EDIT: Or maybe it's just noise in the measurements...

[sharkdp]

EDIT: Or maybe it's just noise in the measurements...

Hm, yeah. I'd be surprised if it did improve for the builtin cache as well.

[sharkdp]

Quoting myself:

So how do we deal with this?

• First: we should improve the documentation and add a warning that custom syntaxes and themes lead to a significant slowdown in startup speed (almost factor of 2).
• As a workaround for you, you can run bat cache --clear to hopefully get back to the "old" startup speed of ~ 50 ms. If you want to keep your custom syntaxes and themes, you could try moving them to a faster filesystem (tmpfs?).

That is not needed anymore after the fix in v0.15 mentioned above.

I have done this in the past, but we should look more carefully into methods to decrease the startup speed of bat, for both cases.

• Somehow parallelize the deserialization process (by splitting up the binaries into smaller chunks. After all, they are made out of ~100 different syntaxes and themes)

• Only load syntaxes and themes "on demand". If syntaxes and themes were serialized separately, we might be able to load them on demand. It's probably not as easy as it sounds, because syntaxes are interlinked (code blocks in markdown files could require the loading of all kinds of syntaxes, for example).

• Try to look into ways to improve the deserialization speed.

• The assets are currently stored in compressed form. I think I have tried storing them in uncompressed form once (and didn't see any performance improvements), but it might be worth re-evaluating that.

This would still be great. I'm going to open a new ticket to address startup speed in particular.

The other issues in this ticket seem to be resolved?