The sound distributed version control system

#849 pijul record failed under FreeBSD - Error: No such file or directory (os error 2)

Opened by levi on December 25, 2023
levi on December 25, 2023

pijul record Unexpected : Error: No such file or directory (os error 2) under FreeBSD 14.0-RELEASE-p3 on pijul 1.0.0-beta.7 From what I can see, this is a fairly common Rust I/O error. I don’t yet know what exactly caused it. But I know what I did, I changed the permissions to the directories in the repository. Most likely pijul does not have the right to read the files. Investigating…

tankf33der on December 25, 2023

Freebsd?

levi on December 25, 2023

Yes, FreeBSD. Sorry for incomplete uname I’m attaching the repository: https://we.tl/t-El0VYOlvpK for investigation. For I’m almost sure this is the permissions issues.

levi closed this discussion on December 25, 2023
levi reopened this discussion on December 25, 2023
tankf33der on December 25, 2023

Why you ever touched permissions? :) Permissions of what?

levi on December 25, 2023

File Permissions in the repository, of course. Why ? It’s quite simple. I made a backup on my USB drive. FAT does not carry other file systems file permissions. So I want to fix them. And I saw this error, which is probably caused by that, although I’m not 100% sure because I recently compiled a new pijul.

tankf33der on December 25, 2023

successfully recorded inside your repo under linux under mainstream pijul’s version.

[mpech@lambda dotbck]$ touch a
[mpech@lambda dotbck]$ pi add a
Tracked 1 path(s)
[mpech@lambda dotbck]$ pir
Hash: 4JA6MCSDPSWVC4RJZYJXKZPCSMPZPNFKNUENPLFESZ44JX5UL2MQC
[mpech@lambda dotbck]$ 
levi on December 25, 2023
Orion% pwd
/home/levi/Pobrane
Orion% ls -al
total 43
drwxr-xr-x   2 levi levi     3 25 gru 18:30 .
drwxr-xr-x  19 levi levi    31 25 gru 18:29 ..
-rw-r--r--   1 levi levi 10305 25 gru 18:30 dotbck.tar.gz
Orion% tar -xvzf dotbck.tar.gz 
x dotbck/
x dotbck/.pijul/
x dotbck/.stow-local-ignore
x dotbck/zsh/
x dotbck/nvim/
x dotbck/starship/
x dotbck/alacritty/
x dotbck/helix/
x dotbck/.ignore
x dotbck/helix/.config/
x dotbck/helix/.config/config.toml
x dotbck/alacritty/.config/
x dotbck/alacritty/.config/future-alacritty.toml
x dotbck/alacritty/.config/alacritty.yml
x dotbck/starship/.config/
x dotbck/starship/.config/starship.toml
x dotbck/nvim/.config/
x dotbck/nvim/.config/config.toml
x dotbck/zsh/.zshrc
x dotbck/.pijul/pristine/
x dotbck/.pijul/config
x dotbck/.pijul/changes/
x dotbck/.pijul/identities/
x dotbck/.pijul/changes/SS/
x dotbck/.pijul/changes/5Y/
x dotbck/.pijul/changes/5S/
x dotbck/.pijul/changes/BQ/
x dotbck/.pijul/changes/BQ/6CNSQFIKTBGWMJ7LFBE3JIFB4ESXPLOHQC3BX7P7EHDBHLS6LAC.change
x dotbck/.pijul/changes/5S/GYKKXPJ5FY56ZZMSIJJS325A36HGA7D444FAAZAT5JQE4UXBJAC.change
x dotbck/.pijul/changes/5Y/7YZ7TYORPATBRMHCQMSCHPYOMTI7H26JAZ2L3FPDNIK5KSKSLQC.change
x dotbck/.pijul/changes/SS/KQYKI5O5FNB6VEN7PRGHG5X7RFO6OXXVSTWW24PLHV3ZHS3LPQC.change
x dotbck/.pijul/pristine/db.lock1
x dotbck/.pijul/pristine/db.lock0
x dotbck/.pijul/pristine/db
Orion% cd dotbck
Orion% touch a
Orion% pijul add a
Tracked 1 path(s)
Orion% pijul rec
Error: No such file or directory (os error 2)
Orion% 
tankf33der on December 25, 2023

Looks like pijul is ok here.

levi on December 25, 2023

Now I noticed that my other repositories have the same problem. Some of them…

Well… this is not cool. I was expecting something much, much simpler… Because now it looks like a system-dependent problem, or worse a system-dependent problem inside the Rust I/O library. I think it’s time to compile 8.beta. We’ll see what comes of it. Investigating…

tankf33der on December 25, 2023

I fought with os error 17 for two weeks on unstable linux kernel with latest pijul. Good luck.

tankf33der on December 25, 2023

Since this is not pijul issue you should focus on latest stable freebsd and rustc

levi on December 25, 2023

My FreeBSD 14.0-RELEASE-p3 is stable. FreeBSD unlike Linux has its base separated from the rest of applications. Base system is a monolith. There is nothing you can replace or add like in Linux. Unless you want to build the base and tweak it a bit. But whats default is mostly fine. And it is released by one and the same team. And it is as independent of all the rest as possible. There is nothing more stable in this damn world than stable Release of FreeBSD.

Orion% rustc -V
rustc 1.74.1 (a28077b28 2023-12-04) (built from a source tarball)

Seems stable. In fact, no one puts anything unstable into the source ports. Because whole ports tree depend on it. My system consists of around ~800 packages, everything compiled from source ports, including C compiler + GCC(Some Jester, set it as dependency for fusefs module) So it is stable. I don’t think it is the fault of the system or the compiler.

Now I have close look on how to build pijul. https://cgit.freebsd.org/ports/tree/devel/pijul/Makefile?id=8a8fa07ae51bd324d2eb9f973029193bff56c4bb

The list of dependencies in this Makefile is insanely long. I think someone just dumped all what he has :| Should it look like this ? I guess not. Maybe there is a method in this madness, I have not yet written a port for Rust applications. But if it’s dependencies then they should be pulled in automatically. There are even bunch of windows and winapi entires.

levi on December 25, 2023

I rebuilt pijul to beta-8 version, but I get the same error. FreeBSD updates lang/rust every 6 weeks, to the stable version so I will still wait a bit.

edit: In any case, I sent a patch for beta-8 upstream to the port maintainer. Maybe it is just me.

tankf33der on December 25, 2023

You could upgrade rust to nightly 1.77. Fortunately it is easy switch back to stable via rustup.

joyously on December 26, 2023

This reminds me of how the error messages should include more information discussion.

levi on December 26, 2023

You could upgrade rust to nightly 1.77. Fortunately it is easy switch back to stable via rustup.

I have ‘lang/rust-nightly’ in the ports. I don’t need to switch back. I have boot enviroment so I can rollback to previous snapshot. I gritted my teeth and recompiled nightly and of course pijul. But it didn’t help. The error message is formatted a little differently. But the content is the same.

This reminds me of how the error messages should include more information discussion.

It’s a little more complicated. Because when you type that in the search engine, you will get dozens of results from different rust projects. This is implementation of Rust I/O and errno numbers, these numbers are defined for every UNIX system in errno.h system header file and implemented in libc or other low level system library that interact with the kernel. This is generic rust error msg for errno 2 In C we have perror() and strerror() Where you handle the error yourself. Likely rust provide this default.

That’s why I don’t think it’s pijul’s fault. Anyway, under Linux everything works. I blame low level Rust I/O bindings. Because rust can’t use system header files or C sources, it needs “glue”. And I found something like this in pijul dependencies.

rustix-0.37.26 \
rustix-0.38.20 \

Is it at all normal for dependencies to duplicate in the rust ecosystem ?

https://github.com/bytecodealliance/rustix

Safe Rust bindings to POSIX-ish APIs

The linux_raw backend is enabled by default on platforms which support it. To enable the libc backend instead, either enable the “use-libc” cargo feature, or set the RUSTFLAGS environment variable to –cfg=rustix_use_libc when building.

I am trying to rebuild it with the use-libc flag. I don’t know if I’m not overcomplicating. But I’m running out of other ideas.

levi on December 26, 2023

Another hint: Testing this on my dotbck repository.

Orion% touch z
Orion% pijul add z
Tracked 1 path(s)
Orion% pijul rec
Error: No such file or directory (os error 2)
Orion% pijul rec -a
Error: No change message
Orion% pijul rec -a -m
error: The argument '--message <MESSAGE>' requires a value but none was supplied
For more information try --help
Orion% pijul rec -a -m done
Hash: X3HN3A5N4R3BHZY7QE2BAWIGEBLEDZT43ZX3NFPYEYRO4LWJIIMAC

So now pijul require -a flag ? It used to be that -a was the default. And it seems to me that it continues to be so. Has anything changed in this regard ? In general, since when does this flag exist ? Because I never used it. I’m lost here…

tankf33der on December 26, 2023

Pijul behaves correctly. I am always using:pijul record -am.

since i hate log messages.

levi on December 26, 2023

Debug log at the request of @tankf33der

Orion% cd
Orion% pijul init p1
Repository created at p1
Orion% cd p1
Orion% touch a
Orion% pijul add a
Tracked 1 path(s)
Orion% RUST_LOG="pijul=debug,libpijul=debug" pijul rec
[2023-12-26T19:36:57Z DEBUG pijul::repository] "/home/levi/p1/.pijul"
[2023-12-26T19:36:57Z DEBUG pijul::repository] max_files = 19553
[2023-12-26T19:36:57Z DEBUG libpijul::small_string] onpage_size [4, 109, 97, 105, 110]
[2023-12-26T19:36:57Z DEBUG libpijul::small_string] onpage_size [4, 109, 97, 105, 110]
[2023-12-26T19:36:57Z DEBUG libpijul::pristine::sanakirja] load_channel: "main" SerializedChannel { graph: L64(61440), changes: L64(65536), revchanges: L64(69632), states: L64(73728), tags: L64(77824), apply_counter: L64(0), last_modified: L64(0), id: F4M2GVAIRWHA67ZL5W3CWWQ254 }
[2023-12-26T19:36:57Z DEBUG libpijul::change] make_change, contents_hash = ZP5DHSPEAGVWCFG5FVOUF62IOH4HVMZF7Q6XIINYJY7LY4YVWI7AC
[2023-12-26T19:36:57Z DEBUG libpijul::change] EQEKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC
[2023-12-26T19:36:57Z INFO libpijul::change] compressing with ZStd 1.5.5
[2023-12-26T19:36:57Z DEBUG libpijul::change] compressed hashed in 229.19µs
[2023-12-26T19:36:57Z INFO libpijul::change] compressing with ZStd 1.5.5
[2023-12-26T19:36:57Z DEBUG libpijul::change] compressed unhashed in 3.42µs
[2023-12-26T19:36:57Z INFO libpijul::change] compressing with ZStd 1.5.5
[2023-12-26T19:36:57Z DEBUG libpijul::change] compressed 32 bytes of contents in 13.97µs
[2023-12-26T19:36:57Z DEBUG libpijul::change] change serialized
[2023-12-26T19:36:57Z DEBUG libpijul::changestore::filesystem] file_name = "/home/levi/p1/.pijul/changes/EQ/EKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC.change"
[2023-12-26T19:36:57Z DEBUG libpijul::apply] apply_change "EQEKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC"
[2023-12-26T19:36:57Z DEBUG libpijul::changestore::filesystem] file_name = "/home/levi/p1/.pijul/changes/EQ/EKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC.change"
[2023-12-26T19:36:57Z DEBUG libpijul::change] offsets = Offsets { version: 6, hashed_len: 257, unhashed_off: 214, unhashed_len: 0, contents_off: 252, contents_len: 32, total: 322 }
[2023-12-26T19:36:57Z DEBUG libpijul::change] parsing unhashed: Ok("")
[2023-12-26T19:36:57Z DEBUG libpijul::change] unhashed = None
[2023-12-26T19:36:57Z DEBUG libpijul::change] contents = [74, 158, 165, 74, 184, 20, 56, 232, 216, 202, 221, 105, 237, 154, 212, 174, 35, 110, 172, 217, 153, 80, 164, 110, 138, 176, 57, 102, 46, 142, 193, 18]
[2023-12-26T19:36:57Z DEBUG libpijul::pristine::sanakirja] get_external ChangeId(EQEKBFCUCVZGU)
[2023-12-26T19:36:57Z DEBUG libpijul::pristine] registering change EQEKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC
[2023-12-26T19:36:57Z DEBUG libpijul::pristine] touched: Position { change: ChangeId(AAAAAAAAAAAAA), pos: ChangePosition(L64(0)) } ChangeId(EQEKBFCUCVZGU)
[2023-12-26T19:36:57Z DEBUG libpijul::pristine] touched: Position { change: ChangeId(AAAAAAAAAAAAA), pos: ChangePosition(L64(0)) } ChangeId(EQEKBFCUCVZGU)
[2023-12-26T19:36:57Z DEBUG libpijul::apply] internal = ChangeId(EQEKBFCUCVZGU)
[2023-12-26T19:36:57Z DEBUG libpijul::apply] apply_change_to_channel ChangeId(EQEKBFCUCVZGU) EQEKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC
[2023-12-26T19:36:57Z DEBUG libpijul::pristine::sanakirja] put_changes ChangeId(EQEKBFCUCVZGU) EQEKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC
[2023-12-26T19:36:57Z DEBUG libpijul::pristine::sanakirja] get_changeset = None
[2023-12-26T19:36:57Z DEBUG libpijul::pristine::sanakirja] put_changes 0 ChangeId(EQEKBFCUCVZGU)
[2023-12-26T19:36:57Z DEBUG libpijul::apply] apply change to channel
[2023-12-26T19:36:57Z DEBUG libpijul::apply] Applying AddRoot { name: NewVertex(NewVertex { up_context: [Position { change: Some(AA), pos: ChangePosition(L64(0)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(0)), end: ChangePosition(L64(0)), inode: Position { change: Some(AA), pos: ChangePosition(L64(0)) } }), inode: NewVertex(NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(0)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(1)), end: ChangePosition(L64(1)), inode: Position { change: Some(AA), pos: ChangePosition(L64(0)) } }) } (1)
[2023-12-26T19:36:57Z DEBUG libpijul::pristine::sanakirja] find_block_end, no prev
[2023-12-26T19:36:57Z DEBUG libpijul::pristine::sanakirja] find_block: BLOCK ERROR
[2023-12-26T19:36:57Z DEBUG libpijul::apply::vertex] put_newvertex V(ChangeId(EQEKBFCUCVZGU)[0:0]) [Position { change: Some(AA), pos: ChangePosition(L64(0)) }] [] BLOCK | FOLDER ChangeId(EQEKBFCUCVZGU)
[2023-12-26T19:36:57Z DEBUG libpijul::apply::vertex] up_vertex V(ChangeId(AAAAAAAAAAAAA)[0:0])
[2023-12-26T19:36:57Z DEBUG libpijul::apply::vertex] deleted by: {}
[2023-12-26T19:36:57Z DEBUG libpijul::pristine] put_graph_with_rev V(ChangeId(AAAAAAAAAAAAA)[0:0]) V(ChangeId(EQEKBFCUCVZGU)[0:0]) BLOCK | FOLDER
[2023-12-26T19:36:57Z DEBUG libpijul::apply::vertex] down_context []
[2023-12-26T19:36:57Z DEBUG libpijul::pristine::sanakirja] find_block_end, loop, k = V(ChangeId(EQEKBFCUCVZGU)[0:0]), p = Position { change: ChangeId(EQEKBFCUCVZGU), pos: ChangePosition(L64(1)) }
[2023-12-26T19:36:57Z DEBUG libpijul::pristine::sanakirja] find_block_end, V(ChangeId(EQEKBFCUCVZGU)[0:0]) Position { change: ChangeId(EQEKBFCUCVZGU), pos: ChangePosition(L64(1)) }
[2023-12-26T19:36:57Z DEBUG libpijul::pristine::sanakirja] find_block_end, V(ChangeId(EQEKBFCUCVZGU)[0:0]) Position { change: ChangeId(EQEKBFCUCVZGU), pos: ChangePosition(L64(1)) }
[2023-12-26T19:36:57Z DEBUG libpijul::pristine::sanakirja] find_block_end: BLOCK ERROR
[2023-12-26T19:36:57Z DEBUG libpijul::pristine::sanakirja] find_block: BLOCK ERROR
[2023-12-26T19:36:57Z DEBUG libpijul::apply::vertex] put_newvertex V(ChangeId(EQEKBFCUCVZGU)[1:1]) [Position { change: None, pos: ChangePosition(L64(0)) }] [] BLOCK | FOLDER ChangeId(EQEKBFCUCVZGU)
[2023-12-26T19:36:57Z DEBUG libpijul::apply::vertex] put_up_context Position { change: ChangeId(EQEKBFCUCVZGU), pos: ChangePosition(L64(0)) }
[2023-12-26T19:36:57Z DEBUG libpijul::pristine::sanakirja] find_block_end, loop, k = V(ChangeId(EQEKBFCUCVZGU)[0:0]), p = Position { change: ChangeId(EQEKBFCUCVZGU), pos: ChangePosition(L64(0)) }
[2023-12-26T19:36:57Z DEBUG libpijul::apply::vertex] k = V(ChangeId(EQEKBFCUCVZGU)[0:0])
[2023-12-26T19:36:57Z DEBUG libpijul::apply::vertex] up_vertex V(ChangeId(EQEKBFCUCVZGU)[0:0])
[2023-12-26T19:36:57Z DEBUG libpijul::apply::vertex] deleted by: {}
[2023-12-26T19:36:57Z DEBUG libpijul::pristine] put_graph_with_rev V(ChangeId(EQEKBFCUCVZGU)[0:0]) V(ChangeId(EQEKBFCUCVZGU)[1:1]) BLOCK | FOLDER
[2023-12-26T19:36:57Z DEBUG libpijul::apply::vertex] down_context []
[2023-12-26T19:36:57Z DEBUG libpijul::apply] Applying AddRoot { name: NewVertex(NewVertex { up_context: [Position { change: Some(AA), pos: ChangePosition(L64(0)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(0)), end: ChangePosition(L64(0)), inode: Position { change: Some(AA), pos: ChangePosition(L64(0)) } }), inode: NewVertex(NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(0)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(1)), end: ChangePosition(L64(1)), inode: Position { change: Some(AA), pos: ChangePosition(L64(0)) } }) } (2)
[2023-12-26T19:36:57Z INFO libpijul::apply] repairing missing contexts
[2023-12-26T19:36:57Z DEBUG libpijul::missing_context] repair_parents_of_deleted
[2023-12-26T19:36:57Z DEBUG libpijul::missing_context] no pseudo edges
[2023-12-26T19:36:57Z INFO libpijul::apply] done applying change
[2023-12-26T19:36:57Z INFO libpijul::record] Starting to record
[2023-12-26T19:36:57Z DEBUG libpijul::record] stack.pop() = Some(RecordItem { v_papa: Position { change: Some(ChangeId(AAAAAAAAAAAAA)), pos: ChangePosition(L64(0)) }, papa: Inode(AAAAAAAAAAAAA), inode: Inode(AAAAAAAAAAAAA), basename: "", full_path: "", metadata: InodeMetadata(512) })
[2023-12-26T19:36:57Z DEBUG libpijul::record] TAKING LOCK 362
[2023-12-26T19:36:57Z DEBUG libpijul::record] TAKEN
[2023-12-26T19:36:57Z DEBUG libpijul::record] delete_obsolete_children, v = Position { change: ChangeId(EQEKBFCUCVZGU), pos: ChangePosition(L64(1)) }
[2023-12-26T19:36:57Z DEBUG libpijul::record] has_nonempty_root: false
[2023-12-26T19:36:57Z DEBUG libpijul::record] root_vertices: [Position { change: ChangeId(EQEKBFCUCVZGU), pos: ChangePosition(L64(1)) }]
[2023-12-26T19:36:57Z DEBUG libpijul::record] push_children, vertex = Position { change: Some(ChangeId(EQEKBFCUCVZGU)), pos: ChangePosition(L64(1)) }, item = RecordItem { v_papa: Position { change: Some(ChangeId(EQEKBFCUCVZGU)), pos: ChangePosition(L64(1)) }, papa: Inode(AAAAAAAAAAAAA), inode: Inode(AAAAAAAAAAAAA), basename: "", full_path: "", metadata: InodeMetadata(512) }
[2023-12-26T19:36:57Z DEBUG libpijul::record] fileid = OwnedPathId { parent_inode: Inode(AAAAAAAAAAAAA), basename: "" }
[2023-12-26T19:36:57Z DEBUG libpijul::record] push_children Inode(AAAAAAAAAAAAA):a Inode(4YJI5IKIALX7S)
[2023-12-26T19:36:57Z DEBUG libpijul::record] fileid_ Inode(AAAAAAAAAAAAA):a child_inode Inode(4YJI5IKIALX7S)
[2023-12-26T19:36:57Z DEBUG libpijul::working_copy::filesystem] metadata "a"
[2023-12-26T19:36:57Z DEBUG libpijul::working_copy::filesystem] permissions = 33188
[2023-12-26T19:36:57Z DEBUG libpijul::record] full_path = "a", meta = InodeMetadata(0)
[2023-12-26T19:36:57Z DEBUG libpijul::record] push_children done
[2023-12-26T19:36:57Z DEBUG libpijul::record] stack.pop() = Some(RecordItem { v_papa: Position { change: Some(ChangeId(EQEKBFCUCVZGU)), pos: ChangePosition(L64(1)) }, papa: Inode(AAAAAAAAAAAAA), inode: Inode(4YJI5IKIALX7S), basename: "a", full_path: "a", metadata: InodeMetadata(0) })
[2023-12-26T19:36:57Z DEBUG libpijul::record] TAKING LOCK 449
[2023-12-26T19:36:57Z DEBUG libpijul::record] record_file_addition RecordItem { v_papa: Position { change: Some(ChangeId(EQEKBFCUCVZGU)), pos: ChangePosition(L64(1)) }, papa: Inode(AAAAAAAAAAAAA), inode: Inode(4YJI5IKIALX7S), basename: "a", full_path: "a", metadata: InodeMetadata(0) }
[2023-12-26T19:36:57Z DEBUG libpijul::working_copy::filesystem] metadata "a"
[2023-12-26T19:36:57Z DEBUG libpijul::working_copy::filesystem] permissions = 33188
[2023-12-26T19:36:57Z DEBUG libpijul::working_copy::filesystem] read_file "a"
[2023-12-26T19:36:57Z DEBUG libpijul::record] FileAdd { add_name: NewVertex(NewVertex { up_context: [Position { change: Some(ChangeId(EQEKBFCUCVZGU)), pos: ChangePosition(L64(1)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(3)), end: ChangePosition(L64(28)), inode: Position { change: Some(ChangeId(EQEKBFCUCVZGU)), pos: ChangePosition(L64(1)) } }), add_inode: NewVertex(NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(28)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(1)), end: ChangePosition(L64(1)), inode: Position { change: Some(ChangeId(EQEKBFCUCVZGU)), pos: ChangePosition(L64(1)) } }), contents: None, path: "a", encoding: Some(Encoding(Encoding { UTF-8 })) }
[2023-12-26T19:36:57Z INFO libpijul::record] stop work
[2023-12-26T19:36:57Z DEBUG libpijul::record] waiting, stop = true
[2023-12-26T19:36:57Z INFO libpijul::record] record done
[2023-12-26T19:36:57Z DEBUG libpijul::record] result = [FileAdd { add_name: NewVertex(NewVertex { up_context: [Position { change: Some(ChangeId(EQEKBFCUCVZGU)), pos: ChangePosition(L64(1)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(3)), end: ChangePosition(L64(28)), inode: Position { change: Some(ChangeId(EQEKBFCUCVZGU)), pos: ChangePosition(L64(1)) } }), add_inode: NewVertex(NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(28)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(1)), end: ChangePosition(L64(1)), inode: Position { change: Some(ChangeId(EQEKBFCUCVZGU)), pos: ChangePosition(L64(1)) } }), contents: None, path: "a", encoding: Some(Encoding(Encoding { UTF-8 })) }], updatables = {1: Add { pos: ChangePosition(L64(1)), inode: Inode(4YJI5IKIALX7S) }}
[2023-12-26T19:36:57Z DEBUG pijul::commands::record] TAKING LOCK 385
[2023-12-26T19:36:57Z DEBUG libpijul::pristine::sanakirja] get_external ChangeId(EQEKBFCUCVZGU)
[2023-12-26T19:36:57Z DEBUG libpijul::pristine::sanakirja] get_external ChangeId(EQEKBFCUCVZGU)
[2023-12-26T19:36:57Z DEBUG libpijul::pristine::sanakirja] get_external ChangeId(EQEKBFCUCVZGU)
[2023-12-26T19:36:57Z DEBUG libpijul::change] h = EQEKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC
[2023-12-26T19:36:57Z DEBUG libpijul::change] id = ChangeId(EQEKBFCUCVZGU)
[2023-12-26T19:36:57Z DEBUG libpijul::change] time = 0
[2023-12-26T19:36:57Z DEBUG libpijul::pristine::sanakirja] get_external ChangeId(EQEKBFCUCVZGU)
[2023-12-26T19:36:57Z DEBUG libpijul::change] make_change, contents_hash = KOI4CZTR7EWEVN6GXV3MU2KRIPS53EI3XEWQPMS5HKB54ALZQXQAC
[2023-12-26T19:36:57Z DEBUG pijul::commands::record] has_binary = false
[2023-12-26T19:36:57Z DEBUG pijul::commands::record] write change
[2023-12-26T19:36:57Z DEBUG libpijul::change::text_changes] write FileAdd { add_name: NewVertex(NewVertex { up_context: [Position { change: Some(EQEKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC), pos: ChangePosition(L64(1)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(3)), end: ChangePosition(L64(28)), inode: Position { change: Some(EQEKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC), pos: ChangePosition(L64(1)) } }), add_inode: NewVertex(NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(28)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(1)), end: ChangePosition(L64(1)), inode: Position { change: Some(EQEKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC), pos: ChangePosition(L64(1)) } }), contents: None, path: "a", encoding: Some(Encoding(Encoding { UTF-8 })) }
[2023-12-26T19:36:57Z DEBUG libpijul::change::text_changes] add_name NewVertex { up_context: [Position { change: Some(EQEKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC), pos: ChangePosition(L64(1)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(3)), end: ChangePosition(L64(28)), inode: Position { change: Some(EQEKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC), pos: ChangePosition(L64(1)) } }
[2023-12-26T19:36:57Z DEBUG pijul::commands::record] write change done
message = 'Test'
timestamp = '2023-12-26T19:36:57.362438733Z'

[[authors]]
key = 'BRtGL5K2xo7cmkjAwZ6F55vHNdTSyd6cFPisjX5oLNqB'

# Dependencies
[2] EQEKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC #

# Hunks

1. File addition: "a" in "" "UTF-8"
  up 2.1, new 3:28
~
~
~
~
~
~
~
~
~
~
~
~
~
~
~
~
~
~
~
/tmp/.tmpTIkwa8.toml: 13 linii, 270 znaków.
[2023-12-26T19:37:07Z DEBUG libpijul::change::parse] parse_hunk " File addition: \"a\" in \"\" \"UTF-8\"\n  up 2.1, new 3:28\n"
[2023-12-26T19:37:07Z DEBUG libpijul::change::text_changes] from_printable FileAddition { name: "a", parent: "", perms: IsFile, encoding: Some(Encoding(Encoding { UTF-8 })), up_context: [PrintablePos(2, 1)], start: 3, end: 28, contents: [] }
[2023-12-26T19:37:07Z DEBUG libpijul::change::text_changes] change_ref {2: EQEKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC} 2
[2023-12-26T19:37:07Z DEBUG libpijul::change::text_changes] res = FileAdd { add_name: NewVertex(NewVertex { up_context: [Position { change: Some(EQEKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC), pos: ChangePosition(L64(1)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(0)), end: ChangePosition(L64(25)), inode: Position { change: Some(AA), pos: ChangePosition(L64(0)) } }), add_inode: NewVertex(NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(25)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(26)), end: ChangePosition(L64(26)), inode: Position { change: Some(AA), pos: ChangePosition(L64(0)) } }), contents: None, path: "a", encoding: Some(Encoding(Encoding { UTF-8 })) }
[2023-12-26T19:37:07Z DEBUG libpijul::change] h = EQEKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC
[2023-12-26T19:37:07Z DEBUG libpijul::change] id = ChangeId(EQEKBFCUCVZGU)
[2023-12-26T19:37:07Z DEBUG libpijul::change] time = 0
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] get_external ChangeId(EQEKBFCUCVZGU)
[2023-12-26T19:37:07Z DEBUG pijul::commands::record] saving change
[2023-12-26T19:37:07Z DEBUG libpijul::change] 2NYFIYOHHN2MWRDTAVFUN6B57ZSODPP7L7UGY7IHVL2JDAQDNQTAC
[2023-12-26T19:37:07Z INFO libpijul::change] compressing with ZStd 1.5.5
[2023-12-26T19:37:07Z DEBUG libpijul::change] compressed hashed in 70.9µs
[2023-12-26T19:37:07Z INFO libpijul::change] compressing with ZStd 1.5.5
[2023-12-26T19:37:07Z DEBUG libpijul::change] compressed unhashed in 17.47µs
[2023-12-26T19:37:07Z INFO libpijul::change] compressing with ZStd 1.5.5
[2023-12-26T19:37:07Z DEBUG libpijul::change] compressed 28 bytes of contents in 17.12µs
[2023-12-26T19:37:07Z DEBUG libpijul::change] change serialized
[2023-12-26T19:37:07Z DEBUG libpijul::changestore::filesystem] file_name = "/home/levi/p1/.pijul/changes/2N/YFIYOHHN2MWRDTAVFUN6B57ZSODPP7L7UGY7IHVL2JDAQDNQTAC.change"
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] get_external ChangeId(2NYFIYOHHN2MW)
[2023-12-26T19:37:07Z DEBUG libpijul::apply] make_changeid 2NYFIYOHHN2MWRDTAVFUN6B57ZSODPP7L7UGY7IHVL2JDAQDNQTAC ChangeId(2NYFIYOHHN2MW)
[2023-12-26T19:37:07Z DEBUG libpijul::pristine] registering change 2NYFIYOHHN2MWRDTAVFUN6B57ZSODPP7L7UGY7IHVL2JDAQDNQTAC
[2023-12-26T19:37:07Z DEBUG libpijul::pristine] dep = EQEKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC
[2023-12-26T19:37:07Z DEBUG libpijul::pristine] ChangeId(2NYFIYOHHN2MW) depends on ChangeId(EQEKBFCUCVZGU)
[2023-12-26T19:37:07Z DEBUG libpijul::pristine] touched: Position { change: ChangeId(AAAAAAAAAAAAA), pos: ChangePosition(L64(0)) } ChangeId(2NYFIYOHHN2MW)
[2023-12-26T19:37:07Z DEBUG libpijul::pristine] touched: Position { change: ChangeId(AAAAAAAAAAAAA), pos: ChangePosition(L64(0)) } ChangeId(2NYFIYOHHN2MW)
[2023-12-26T19:37:07Z DEBUG libpijul::apply] apply_change_to_channel ChangeId(2NYFIYOHHN2MW) 2NYFIYOHHN2MWRDTAVFUN6B57ZSODPP7L7UGY7IHVL2JDAQDNQTAC
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] put_changes ChangeId(2NYFIYOHHN2MW) 2NYFIYOHHN2MWRDTAVFUN6B57ZSODPP7L7UGY7IHVL2JDAQDNQTAC
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] get_changeset = None
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] put_changes 1 ChangeId(2NYFIYOHHN2MW)
[2023-12-26T19:37:07Z DEBUG libpijul::apply] apply change to channel
[2023-12-26T19:37:07Z DEBUG libpijul::apply] Applying FileAdd { add_name: NewVertex(NewVertex { up_context: [Position { change: Some(EQEKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC), pos: ChangePosition(L64(1)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(0)), end: ChangePosition(L64(25)), inode: Position { change: Some(AA), pos: ChangePosition(L64(0)) } }), add_inode: NewVertex(NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(25)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(26)), end: ChangePosition(L64(26)), inode: Position { change: Some(AA), pos: ChangePosition(L64(0)) } }), contents: None, path: "a", encoding: Some(Encoding(Encoding { UTF-8 })) } (1)
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] find_block_end, loop, k = V(ChangeId(EQEKBFCUCVZGU)[1:1]), p = Position { change: ChangeId(2NYFIYOHHN2MW), pos: ChangePosition(L64(25)) }
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] find_block_end, V(ChangeId(EQEKBFCUCVZGU)[1:1]) Position { change: ChangeId(2NYFIYOHHN2MW), pos: ChangePosition(L64(25)) }
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] find_block_end, V(ChangeId(EQEKBFCUCVZGU)[1:1]) Position { change: ChangeId(2NYFIYOHHN2MW), pos: ChangePosition(L64(25)) }
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] find_block_end: BLOCK ERROR
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] find_block: BLOCK ERROR
[2023-12-26T19:37:07Z DEBUG libpijul::apply::vertex] put_newvertex V(ChangeId(2NYFIYOHHN2MW)[0:25]) [Position { change: Some(EQEKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC), pos: ChangePosition(L64(1)) }] [] BLOCK | FOLDER ChangeId(2NYFIYOHHN2MW)
[2023-12-26T19:37:07Z DEBUG libpijul::apply::vertex] put_up_context Position { change: ChangeId(EQEKBFCUCVZGU), pos: ChangePosition(L64(1)) }
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] find_block_end, loop, k = V(ChangeId(EQEKBFCUCVZGU)[1:1]), p = Position { change: ChangeId(EQEKBFCUCVZGU), pos: ChangePosition(L64(1)) }
[2023-12-26T19:37:07Z DEBUG libpijul::apply::vertex] k = V(ChangeId(EQEKBFCUCVZGU)[1:1])
[2023-12-26T19:37:07Z DEBUG libpijul::apply::vertex] up_vertex V(ChangeId(EQEKBFCUCVZGU)[1:1])
[2023-12-26T19:37:07Z DEBUG libpijul::apply::vertex] deleted by: {}
[2023-12-26T19:37:07Z DEBUG libpijul::pristine] put_graph_with_rev V(ChangeId(EQEKBFCUCVZGU)[1:1]) V(ChangeId(2NYFIYOHHN2MW)[0:25]) BLOCK | FOLDER
[2023-12-26T19:37:07Z DEBUG libpijul::apply::vertex] down_context []
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] find_block_end, loop, k = V(ChangeId(2NYFIYOHHN2MW)[0:25]), p = Position { change: ChangeId(2NYFIYOHHN2MW), pos: ChangePosition(L64(26)) }
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] find_block_end, V(ChangeId(2NYFIYOHHN2MW)[0:25]) Position { change: ChangeId(2NYFIYOHHN2MW), pos: ChangePosition(L64(26)) }
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] find_block_end, V(ChangeId(2NYFIYOHHN2MW)[0:25]) Position { change: ChangeId(2NYFIYOHHN2MW), pos: ChangePosition(L64(26)) }
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] find_block_end: BLOCK ERROR
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] find_block: BLOCK ERROR
[2023-12-26T19:37:07Z DEBUG libpijul::apply::vertex] put_newvertex V(ChangeId(2NYFIYOHHN2MW)[26:26]) [Position { change: None, pos: ChangePosition(L64(25)) }] [] BLOCK | FOLDER ChangeId(2NYFIYOHHN2MW)
[2023-12-26T19:37:07Z DEBUG libpijul::apply::vertex] put_up_context Position { change: ChangeId(2NYFIYOHHN2MW), pos: ChangePosition(L64(25)) }
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] find_block_end, loop, k = V(ChangeId(2NYFIYOHHN2MW)[0:25]), p = Position { change: ChangeId(2NYFIYOHHN2MW), pos: ChangePosition(L64(25)) }
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] find_block_end, V(ChangeId(2NYFIYOHHN2MW)[0:25]) Position { change: ChangeId(2NYFIYOHHN2MW), pos: ChangePosition(L64(25)) }
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] find_block_end, V(ChangeId(2NYFIYOHHN2MW)[0:25]) Position { change: ChangeId(2NYFIYOHHN2MW), pos: ChangePosition(L64(25)) }
[2023-12-26T19:37:07Z DEBUG libpijul::apply::vertex] k = V(ChangeId(2NYFIYOHHN2MW)[0:25])
[2023-12-26T19:37:07Z DEBUG libpijul::apply::vertex] up_vertex V(ChangeId(2NYFIYOHHN2MW)[0:25])
[2023-12-26T19:37:07Z DEBUG libpijul::apply::vertex] deleted by: {}
[2023-12-26T19:37:07Z DEBUG libpijul::pristine] put_graph_with_rev V(ChangeId(2NYFIYOHHN2MW)[0:25]) V(ChangeId(2NYFIYOHHN2MW)[26:26]) BLOCK | FOLDER
[2023-12-26T19:37:07Z DEBUG libpijul::apply::vertex] down_context []
[2023-12-26T19:37:07Z DEBUG libpijul::apply] Applying FileAdd { add_name: NewVertex(NewVertex { up_context: [Position { change: Some(EQEKBFCUCVZGURU4AHJF5UKJJDKOLSBLF7DEUZLUYPUW6XYRFY6QC), pos: ChangePosition(L64(1)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(0)), end: ChangePosition(L64(25)), inode: Position { change: Some(AA), pos: ChangePosition(L64(0)) } }), add_inode: NewVertex(NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(25)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(26)), end: ChangePosition(L64(26)), inode: Position { change: Some(AA), pos: ChangePosition(L64(0)) } }), contents: None, path: "a", encoding: Some(Encoding(Encoding { UTF-8 })) } (2)
[2023-12-26T19:37:07Z INFO libpijul::apply] repairing missing contexts
[2023-12-26T19:37:07Z DEBUG libpijul::missing_context] repair_parents_of_deleted
[2023-12-26T19:37:07Z DEBUG libpijul::missing_context] no pseudo edges
[2023-12-26T19:37:07Z INFO libpijul::apply] done applying change
[2023-12-26T19:37:07Z INFO libpijul::apply] updating Add { pos: ChangePosition(L64(26)), inode: Inode(4YJI5IKIALX7S) }
[2023-12-26T19:37:07Z DEBUG libpijul::apply] update_inode Add { pos: ChangePosition(L64(26)), inode: Inode(4YJI5IKIALX7S) }
[2023-12-26T19:37:07Z DEBUG libpijul::apply] Adding inodes: Inode(4YJI5IKIALX7S) Position { change: ChangeId(2NYFIYOHHN2MW), pos: ChangePosition(L64(26)) }
Hash: 2NYFIYOHHN2MWRDTAVFUN6B57ZSODPP7L7UGY7IHVL2JDAQDNQTAC
[2023-12-26T19:37:07Z DEBUG pijul::commands::record] oldest = SystemTime { tv_sec: 0, tv_nsec: 0 }
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] touch_channel: Some(1703619427000)
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] commit_channel "main"
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] Commit_channel.
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] Commit_channel, dbs_channels = Db_ { db: 8192, k: PhantomData<libpijul::small_string::SmallStr>, v: PhantomData<libpijul::pristine::SerializedChannel>, p: PhantomData<sanakirja_core::btree::page_unsized::Page<libpijul::small_string::SmallStr, libpijul::pristine::SerializedChannel>> }
[2023-12-26T19:37:07Z DEBUG libpijul::small_string] onpage_size [4, 109, 97, 105, 110]
[2023-12-26T19:37:07Z DEBUG libpijul::small_string] onpage_size [4, 109, 97, 105, 110]
[2023-12-26T19:37:07Z DEBUG libpijul::small_string] onpage_size [4, 109, 97, 105, 110]
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] channels: 1c000 19000 1a000 1b000 13000
[2023-12-26T19:37:07Z DEBUG libpijul::small_string] writing [4, 109, 97, 105, 110]
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] Commit_channel, self.channels = Db_ { db: 135168, k: PhantomData<libpijul::small_string::SmallStr>, v: PhantomData<libpijul::pristine::SerializedChannel>, p: PhantomData<sanakirja_core::btree::page_unsized::Page<libpijul::small_string::SmallStr, libpijul::pristine::SerializedChannel>> }
[2023-12-26T19:37:07Z DEBUG libpijul::pristine::sanakirja] 14000 15000 1f000 20000 8000 7000 1d000 21000 e000 17000 1e000 18000 d000
levi on December 26, 2023

We have had a little discussion on Zulip with @tankf33der. My hypothesis is that it’s not so much something with the repository file handling, but the temporary pijul record file, that pijul creates in /tmp For this reason, everything seems to work when use the -a option. Thanks to @tankf33der I was able to produce a debug log. The previous log showed the situation when everything is fine. This one will show the situation where changes are still “hanging” in staging and waiting for record. But Error: No such file or directory (os error 2) is what I get. Operation on previous attached dotbck directory.

Anticipating the question, yes, /tmp has full access rights.

drwxrwxrwt 14 root wheel 21 26 gru 22:00 tmp

The reason may be that my file system is ZFS, which is quite peculiar. But as long as pijul it doesn’t use some non-standard features, it should be ok. No additional hardening, no tmpfs, no /tmp encryption.

I am attaching just the last fragment, the rest in file: https://we.tl/t-yxMAVi5UfS

[2023-12-26T21:47:47Z DEBUG pijul::commands::record] TAKING LOCK 385
[2023-12-26T21:47:47Z DEBUG libpijul::pristine::sanakirja] get_external ChangeId(5Y7YZ7TYORPAS)
[2023-12-26T21:47:47Z DEBUG libpijul::pristine::sanakirja] get_external ChangeId(5Y7YZ7TYORPAS)
[2023-12-26T21:47:47Z DEBUG libpijul::pristine::sanakirja] get_external ChangeId(5Y7YZ7TYORPAS)
[2023-12-26T21:47:47Z DEBUG libpijul::change] h = 5Y7YZ7TYORPATBRMHCQMSCHPYOMTI7H26JAZ2L3FPDNIK5KSKSLQC
[2023-12-26T21:47:47Z DEBUG libpijul::change] id = ChangeId(5Y7YZ7TYORPAS)
[2023-12-26T21:47:47Z DEBUG libpijul::change] time = 0
[2023-12-26T21:47:47Z DEBUG libpijul::pristine::sanakirja] get_external ChangeId(5Y7YZ7TYORPAS)
[2023-12-26T21:47:47Z DEBUG libpijul::change] make_change, contents_hash = 2YUN2ZKHJCBCPH6ULWCMI4KD52KWU27XAYCE2U22R3CIFTDAVNZQC
[2023-12-26T21:47:47Z DEBUG pijul::commands::record] has_binary = false
[2023-12-26T21:47:47Z DEBUG pijul::commands::record] write change
[2023-12-26T21:47:47Z DEBUG libpijul::change::text_changes] write FileAdd { add_name: NewVertex(NewVertex { up_context: [Position { change: Some(5Y7YZ7TYORPATBRMHCQMSCHPYOMTI7H26JAZ2L3FPDNIK5KSKSLQC), pos: ChangePosition(L64(1)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(2)), end: ChangePosition(L64(22)), inode: Position { change: Some(5Y7YZ7TYORPATBRMHCQMSCHPYOMTI7H26JAZ2L3FPDNIK5KSKSLQC), pos: ChangePosition(L64(1)) } }), add_inode: NewVertex(NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(22)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(1)), end: ChangePosition(L64(1)), inode: Position { change: Some(5Y7YZ7TYORPATBRMHCQMSCHPYOMTI7H26JAZ2L3FPDNIK5KSKSLQC), pos: ChangePosition(L64(1)) } }), contents: None, path: "alacritty", encoding: None }
[2023-12-26T21:47:47Z DEBUG libpijul::change::text_changes] add_name NewVertex { up_context: [Position { change: Some(5Y7YZ7TYORPATBRMHCQMSCHPYOMTI7H26JAZ2L3FPDNIK5KSKSLQC), pos: ChangePosition(L64(1)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(2)), end: ChangePosition(L64(22)), inode: Position { change: Some(5Y7YZ7TYORPATBRMHCQMSCHPYOMTI7H26JAZ2L3FPDNIK5KSKSLQC), pos: ChangePosition(L64(1)) } }
[2023-12-26T21:47:47Z DEBUG libpijul::change::text_changes] write FileAdd { add_name: NewVertex(NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(1)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(25)), end: ChangePosition(L64(43)), inode: Position { change: None, pos: ChangePosition(L64(1)) } }), add_inode: NewVertex(NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(43)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(24)), end: ChangePosition(L64(24)), inode: Position { change: None, pos: ChangePosition(L64(1)) } }), contents: None, path: "alacritty/.config", encoding: None }
[2023-12-26T21:47:47Z DEBUG libpijul::change::text_changes] add_name NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(1)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(25)), end: ChangePosition(L64(43)), inode: Position { change: None, pos: ChangePosition(L64(1)) } }
[2023-12-26T21:47:47Z DEBUG libpijul::change::text_changes] write FileAdd { add_name: NewVertex(NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(24)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(48)), end: ChangePosition(L64(93)), inode: Position { change: None, pos: ChangePosition(L64(24)) } }), add_inode: NewVertex(NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(93)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(45)), end: ChangePosition(L64(45)), inode: Position { change: None, pos: ChangePosition(L64(24)) } }), contents: Some(NewVertex(NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(45)) }], down_context: [], flag: BLOCK, start: ChangePosition(L64(46)), end: ChangePosition(L64(47)), inode: Position { change: None, pos: ChangePosition(L64(45)) } })), path: "alacritty/.config/future-alacritty.toml", encoding: Some(Encoding(Encoding { UTF-8 })) }
[2023-12-26T21:47:47Z DEBUG libpijul::change::text_changes] add_name NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(24)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(48)), end: ChangePosition(L64(93)), inode: Position { change: None, pos: ChangePosition(L64(24)) } }
[2023-12-26T21:47:47Z DEBUG libpijul::change::text_changes] write FileAdd { add_name: NewVertex(NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(24)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(2691)), end: ChangePosition(L64(2728)), inode: Position { change: None, pos: ChangePosition(L64(24)) } }), add_inode: NewVertex(NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(2728)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(95)), end: ChangePosition(L64(95)), inode: Position { change: None, pos: ChangePosition(L64(24)) } }), contents: Some(NewVertex(NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(95)) }], down_context: [], flag: BLOCK, start: ChangePosition(L64(96)), end: ChangePosition(L64(2690)), inode: Position { change: None, pos: ChangePosition(L64(95)) } })), path: "alacritty/.config/alacritty.yml", encoding: Some(Encoding(Encoding { UTF-8 })) }
[2023-12-26T21:47:47Z DEBUG libpijul::change::text_changes] add_name NewVertex { up_context: [Position { change: None, pos: ChangePosition(L64(24)) }], down_context: [], flag: BLOCK | FOLDER, start: ChangePosition(L64(2691)), end: ChangePosition(L64(2728)), inode: Position { change: None, pos: ChangePosition(L64(24)) } }
[2023-12-26T21:47:47Z DEBUG pijul::commands::record] write change done
[2023-12-26T21:47:47Z ERROR pijul] Error: Os {
    code: 2,
    kind: NotFound,
    message: "No such file or directory",
}
tankf33der on December 26, 2023

Test suite passed all tests under latest openzfs version on linux.

levi on December 26, 2023

Ok… different approach, time for heavy artillery. I baked in debug symbols and I ran a debugging session

(gdb) b main.rs:150
Breakpoint 1 at 0x1a53116: file src/main.rs, line 150.
(gdb) run rec
Starting program: /home/levi/Pobrane/dotbck/pijul rec
[New LWP 233163 of process 99915]
[New LWP 233164 of process 99915]
[New LWP 233165 of process 99915]
[New LWP 233166 of process 99915]
[New LWP 233167 of process 99915]
[New LWP 233168 of process 99915]
[New LWP 233169 of process 99915]
[New LWP 233170 of process 99915]
[New LWP 233171 of process 99915]
[New LWP 233172 of process 99915]
[New LWP 233173 of process 99915]
[New LWP 233174 of process 99915]

Thread 1 hit Breakpoint 1, pijul::main::{async_block#0} () at src/main.rs:150
150	    if cfg!(debug_assertions) {
(gdb) n
151	        env_logger::init();
(gdb) n
155	    let opts = Opts::parse();
(gdb) n
157	    if let Err(e) = run(opts).await {
(gdb) n
157	    if let Err(e) = run(opts).await {
(gdb) n
[Detaching after vfork from child process 99916]
160	        log::error!("Error: {:#?}", e);
(gdb) n
160	        log::error!("Error: {:#?}", e);
(gdb) n
160	        log::error!("Error: {:#?}", e);
(gdb) n
160	        log::error!("Error: {:#?}", e);
(gdb) n
[2023-12-26T23:52:37Z ERROR pijul] Error: Os {
        code: 2,
        kind: NotFound,
        message: "No such file or directory",
    }
161	        match e.downcast::<std::io::Error>() {
(gdb)
161	        match e.downcast::<std::io::Error>() {
(gdb)
162	            Ok(e) if e.kind() == std::io::ErrorKind::BrokenPipe => {}
(gdb)
162	            Ok(e) if e.kind() == std::io::ErrorKind::BrokenPipe => {}
(gdb)
163	            Ok(e) => writeln!(std::io::stderr(), "Error: {}", e).unwrap_or(()),
(gdb)
163	            Ok(e) => writeln!(std::io::stderr(), "Error: {}", e).unwrap_or(()),
(gdb)
Error: No such file or directory (os error 2)
165	        }
(gdb)
166	        std::process::exit(1);
(gdb)
[LWP 233168 of process 99915 exited]
[LWP 233171 of process 99915 exited]
[LWP 233169 of process 99915 exited]
[LWP 233172 of process 99915 exited]
[LWP 233170 of process 99915 exited]
[LWP 233166 of process 99915 exited]
[LWP 233167 of process 99915 exited]
[LWP 233165 of process 99915 exited]
[LWP 233164 of process 99915 exited]
[LWP 233163 of process 99915 exited]
[LWP 233173 of process 99915 exited]
[LWP 233174 of process 99915 exited]
[Inferior 1 (process 99915) exited with code 01]`

If that is not enough, I will do a “step into” tomorrow.

levi on December 27, 2023

oof…

This is how I fixed the bug. Well…maybe not fixed, but muted It. I put RUST_BACKTRACE=0 in my shell config. I don’t know why 1 this is the default on FreeBSD. Or where there are other places where this can be set, or if it can compile in. It is what it is. It’s the error block that causes this bug.

levi on December 27, 2023

I have another hint. Tokio comes with its own tokio::io::bsd module: https://docs.rs/tokio/latest/tokio/io/bsd/index.html

There are two sub modules in tokio::io module

bsd  - FreeBSD and net BSD-specific I/O types.
unix - Unix and net Asynchronous IO structures specific to Unix-like operating system

However, I don’t know if the modules are compiled automatically based on conditional compilation and the detected system, or if programmer have to handle them manually. Or do I have to manually add magic flag to include support for bsd. This goes beyond my superficial knowledge of Rust.

I think that’s it, I’m unlikely to come up with anything else.

tankf33der on January 1, 2024

i believe this can be closed.

testing record works on ZFS and UFS with command pijul record -am.

levi on January 1, 2024

It’s still a bug, and we don’t know the cause, while pijul record -am will work, pijul record will not. While we have some hackish workarounds for the problem. It’s far from solving it. We barely scratch the surface. We do not know the wider repercussions. Because the issue is likely related to #857 as well. There is a fairly solid suspicion that the problem is related to the I/O concurrency on ZFS and FreeBSD. Where the reason may be a missing incomplete/implementation. Especially since ZFS on FreeBSD, unlike UFS, can force a specific AIO implementation to work properly. This particular module implements AioSource kqueue notification. And is what is closely related to the mechanism of I/O concurrency. And there will be more such problems because of it.

I don’t want to close this until any programmer or @pmeunier (who knows this part the best) speaks out. Because the suspicion is very strong. We’re done our best, now it’s time for someone to investigate the code. I don’t want to close topics that give the false impression that the problem has been solved, or the cause has been found. Not yet.

@tankf33der If you could check, still pijul record alone on FreeBSD UFS if you still have your QEMU. The best on that previous repository. We could have a clue that the issue is indeed related to #857

tankf33der on January 2, 2024

Please change subject of discussion to “‘pijul record’ failed under FreeBSD”

tankf33der on January 7, 2024

could you consider closing this discussion since we can not repeat the problem with correct commands order?

tankf33der on January 11, 2024

probably link to #861

levi on January 11, 2024

I will investigate all my Bug’s discussions once again on the new pijul release