I am still have the issue where the some operations runs slowly on my laptop, issue began a weeks ago.

Record linux2x files takes minutes, on vps seconds.

I just tried to look at this again, and have absolutely no idea. I you can send me a log of the slow operation, it could be helpful. Try with RUST_LOG="libpijul=debug" first.

Also, is your hard drive an SSD? If not, and if Pijul becomes more serious, I should probably consider investing in a HDD just to test.

alpha47 - ok
alpha48-nest - slow.

Compilation of lower versions failed to show the timing.

https://envs.sh/Nv.txt

This is the place where losing most of the time, I see on eye how debug output stuck.

Laptop - 1min9sec
VPS - 5sec

...
...

[2021-07-07T05:12:38Z DEBUG libpijul::pristine::sanakirja] get_external ChangeId(AAAAAAAAAAAAA)
[2021-07-07T05:12:38Z DEBUG libpijul::pristine::sanakirja] get_external ChangeId(AAAAAAAAAAAAA)
[2021-07-07T05:12:38Z DEBUG libpijul::pristine::sanakirja] get_external ChangeId(AAAAAAAAAAAAA)
[2021-07-07T05:12:38Z DEBUG libpijul::change] make_change, contents_hash = LP22X6ZJMOFIJDEOCO7CU2LK2FFPESRA2UGVBR6SIJHR3QJERVJAC
[2021-07-07T05:12:38Z DEBUG libpijul::change] 2XD53AUFNLJ7WJVGP3RMIJQSJYA7RG7VHS7WWQJ6Z5F7BGWHE5XAC
XXX <---> here
[2021-07-07T05:13:47Z DEBUG libpijul::changestore::filesystem] file_name = "/home/mpech/linux2x-data/repo/.pijul/changes/2X/D53AUFNLJ7WJVGP3RMIJQSJYA7RG7VHS7WWQJ6Z5F7BGWHE5XAC.change"
[2021-07-07T05:13:47Z DEBUG libpijul::pristine::sanakirja] get_external ChangeId(2XD53AUFNLJ7W)
[2021-07-07T05:13:47Z DEBUG libpijul::apply] make_changeid 2XD53AUFNLJ7WJVGP3RMIJQSJYA7RG7VHS7WWQJ6Z5F7BGWHE5XAC ChangeId(2XD53AUFNLJ7W)
[2021-07-07T05:13:47Z DEBUG libpijul::pristine] registering change 2XD53AUFNLJ7WJVGP3RMIJQSJYA7RG7VHS7WWQJ6Z5F7BGWHE5XAC
[2021-07-07T05:13:47Z DEBUG libpijul::pristine] touched: Position { change: ChangeId(AAAAAAAAAAAAA), pos: ChangePosition(L64(0)) } ChangeId(2XD53AUFNLJ7W)
[2021-07-07T05:13:47Z DEBUG libpijul::pristine] touched: Position { change: ChangeId(AAAAAAAAAAAAA), pos: ChangePosition(L64(0)) } ChangeId(2XD53AUFNLJ7W)
...
...
$

This is add.sh file from linux2x.

This is 5y old cheap laptop with SSD and it compiles pijul fast!.

Modern MacBook Pro add.sh runtime ~40secs.

Just pushed a patch to measure this more precisely. If this is what I think it is, there’s quite some work ahead…

If you want to run the same test with the same debugging information, it would be super useful.

The same debug run as above?

Yes please.

Recompiled, run with debug:

https://envs.sh/NH.txt

the same long run time.

Here we go:

[2021-07-08T12:30:56Z DEBUG libpijul::change] SLJHE2IFQ5BGTDIDZOB5QQUG6SEIWFYVDLDAYHXVAKUCSCWXOOVQC
[2021-07-08T12:30:58Z DEBUG libpijul::change] compressed hashed in 1.350611222s
[2021-07-08T12:30:58Z DEBUG libpijul::change] compressed unhashed in 6.735µs
[2021-07-08T12:32:06Z DEBUG libpijul::change] compressed contents in 68.220256259s
[2021-07-08T12:32:06Z DEBUG libpijul::changestore::filesystem] file_name = "/home/mpech/linux2x-data/repo/.pijul/changes/SL/JHE2IFQ5BGTDIDZOB5QQUG6SEIWFYVDLDAYHXVAKUCSCWXOOVQC.change"

This is slightly scary. Can you check what version of ZStd you have on the different machines you tested on? One possible fix would be to include the source code for ZStd in Libpijul, or “oxidize” it.

This takes about 1s on my machine, with ZStd 1.4.9.

This is ArchLinux based Manjaro distro:

$ pacman -Q | grep zstd
lib32-zstd 1.5.0-2
zstd 1.5.0-1

I’m also curious about the (fast) version on the VPS.

1.4.9 on alpine
1.3.9 on debian10

Alpine is vps, debian is real hardware, they both run in 5secs.

Ok, that definitely sounds like a performance regression, possibly at the interface between ZStd and the seekable format.

I believe the most reasonable thing to do is to rewrite the compressor and decompressor for the seekable format in Rust. They’re 400 lines of C each anyway, both well-written and understandable.

it was fast before alpha.47 or 48 as always before.

What is the process doing while debug output is stuck? Is it running or waiting for the disk?

One process always R and 100% cpu

iotop shows all zeroes, no disk activity at all.

@spacefrogg

clone tankf33der/linux2x repo and run time ./add.sh what is run time?

I believe it’s compressing, so this is likely to happen in the main memory.

@spacefrogg: interested in that too, especially if you can tell us your version of ZStd.

What if conpression thing compiled in debug mode?

It’s C, so I don’t think so for libraries installed by your package manager. My guess is that ZStd has a new “thread-safe” compilation mode, which is the thing possibly causing this. I’m trying to reproduce here.

Running tankf33der/linux2x $ time ./add.sh:

real    0m7.779s
user    0m1.660s
sys     0m0.355s

zstd-seekable version (as per Cargo.nix): 0.1.7

EDIT: I use pijul built from the nix flake of the repo, with nix build pijul-repo#pijul

EDIT2: Discrepancies between real time and the others are due to entering the passphrase for the pijul user key.

Thanks! My question was more about the version of ZStd installed on your system (it’s a C library).

That would be the nixpkgs build of zstd-1.4.5

@tankf33der : So, if you’re feeling lucky today, you might want to install nix on your Manjaro and build pijul with nix build .#pijul (you must enable experimental support for Nix Flakes, see nixos.wiki). This should give you the exact same version that I was using and would help to confirm whether your hardware is part of the problem.

new magic:

• Run this morning ./add.sh again time was 2mins, 2x slower
• add –timestamp 123456 to record call - 5secs
• remove –timestamp 123456 from record call - 5sec

Now add.sh on my laptop runs again 5sec.

After laptop reboot again 1:43min, with --timestamp 123456 back 1:22mins.

I rebuilt pijul using zstd-1.5.0 from nixpkgs/master and I could recreate the issue.

Run time was 1m2s.

So, zstd (or interactions with it) seems to be the culprit.

I have downgraded zstd package from 1.5.0 to 1.4.9 in Manjaro and got back 5sec runtime.

I have added zstd package to IgnorePkg list and happy again.

Also I found regression issue in github

Alright, it seems we know what’s going on here, there’s no need to discuss it anymore. I’m closing this discussion, feel free to reopen if I’m wrong.