`du` panicks due to very low birth time of file

[skbeh]

$ ls -l .cache/ccache
drwxr-xr-x - user user 2023-02-09 11:26  0/
drwxr-xr-x - user user 2023-02-09 11:26  1/
drwxr-xr-x - user user 2023-02-09 11:26  2/
drwxr-xr-x - user user 2023-02-09 11:26  3/
drwxr-xr-x - user user 2023-02-09 11:26  4/
drwxr-xr-x - user user 2023-02-09 11:26  5/
drwxr-xr-x - user user 2023-02-09 11:26  6/
drwxr-xr-x - user user 2023-02-09 11:26  7/
drwxr-xr-x - user user 2023-02-09 11:26  8/
drwxr-xr-x - user user 2023-02-09 11:26  9/
drwxr-xr-x - user user 2023-02-09 11:26  a/
drwxr-xr-x - user user 2023-02-09 11:26  b/
drwxr-xr-x - user user 2023-02-09 11:26  c/
drwxr-xr-x - user user 2023-02-09 11:26  d/
drwxr-xr-x - user user 2023-02-09 11:26  e/
drwxr-xr-x - user user 2023-02-09 11:26  f/
drwxr-xr-x - user user 2022-11-20 22:18  tmp/
$ ls -l .cache/ccache/1
drwxr-xr-x   - user user 2023-02-09 11:50  0/
drwxr-xr-x   - user user 2023-02-09 11:50  1/
drwxr-xr-x   - user user 2023-02-09 11:50  2/
drwxr-xr-x   - user user 2023-02-09 11:50  3/
drwxr-xr-x   - user user 2023-02-09 11:50  4/
drwxr-xr-x   - user user 2023-02-09 11:50  5/
drwxr-xr-x   - user user 2023-02-09 11:50  6/
drwxr-xr-x   - user user 2023-02-09 11:50  7/
drwxr-xr-x   - user user 2023-02-09 11:50  8/
drwxr-xr-x   - user user 2023-02-09 11:50  9/
drwxr-xr-x   - user user 2023-02-09 11:50  a/
drwxr-xr-x   - user user 2023-02-09 11:50  b/
drwxr-xr-x   - user user 2023-02-09 11:50  c/
drwxr-xr-x   - user user 2023-02-09 11:50  d/
drwxr-xr-x   - user user 2023-02-09 11:50  e/
drwxr-xr-x   - user user 2023-02-09 11:50  f/
.rw-r--r-- 190 user user 2023-02-09 11:26  CACHEDIR.TAG
.rw-r--r-- 133 user user 2023-02-09 11:26  stats
$ RUST_BACKTRACE=full du .cache/ccache/1
thread 'main' panicked at 'assertion failed: tv_nsec >= 0 && tv_nsec < NSEC_PER_SEC as i64', library/std/src/sys/unix/time.rs:66:9
stack backtrace:
0:     0x560bfc02cc2a - std::backtrace_rs::backtrace::libunwind::trace::h8705646449fcdebe
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/../../backtrace/src/backtrace/libunwind.rs:93:5
1:     0x560bfc02cc2a - std::backtrace_rs::backtrace::trace_unsynchronized::h28d01d89a8ff7fcd
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
2:     0x560bfc02cc2a - std::sys_common::backtrace::_print_fmt::h567dedd80dfd6cb4
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/sys_common/backtrace.rs:65:5
3:     0x560bfc02cc2a - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::haa2a40947cb119e8
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/sys_common/backtrace.rs:44:22
4:     0x560bfbe1b0be - core::fmt::write::h3a707a9253e9c05a
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/core/src/fmt/mod.rs:1208:17
5:     0x560bfbffa3f2 - std::io::Write::write_fmt::h37756127f3897f3d
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/io/mod.rs:1682:15
6:     0x560bfc02fd6f - std::sys_common::backtrace::_print::he4d2e900b14c2d20
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/sys_common/backtrace.rs:47:5
7:     0x560bfc02fd6f - std::sys_common::backtrace::print::h7805ffe1784d912c
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/sys_common/backtrace.rs:34:9
8:     0x560bfc02f96d - std::panicking::default_hook::{{closure}}::h24b7e78ef7d394a7
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panicking.rs:267:22
9:     0x560bfc02f651 - std::panicking::default_hook::hce783bd4bf40e7b5
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panicking.rs:286:9
10:     0x560bfc0307de - <alloc::boxed::Box<F,A> as core::ops::function::Fn<Args>>::call::h13b7b80bb8e26dbd
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/alloc/src/boxed.rs:2032:9
11:     0x560bfc0307de - std::panicking::rust_panic_with_hook::heac8ae3e13a747ae
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panicking.rs:692:13
12:     0x560bfc030544 - std::panicking::begin_panic_handler::{{closure}}::hc8562d54a563e54d
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panicking.rs:577:13
13:     0x560bfc0304de - std::sys_common::backtrace::__rust_end_short_backtrace::h40df308e4f0a632a
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/sys_common/backtrace.rs:137:18
14:     0x560bfc0304b1 - rust_begin_unwind
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panicking.rs:575:5
15:     0x560bfbd5aca2 - core::panicking::panic_fmt::h429554184794acce
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/core/src/panicking.rs:64:14
16:     0x560bfbd5ad9c - core::panicking::panic::h73760413ef6c70ee
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/core/src/panicking.rs:111:5
17:     0x560bfc0a0529 - uu_du::Stat::new::h511643a68c9a7a0c
18:     0x560bfc0a0b95 - uu_du::du::h43002173d63dc000
19:     0x560bfbe65cca - uu_du::uumain::h648c07fd6943e724
20:     0x560bfbd8fdc3 - coreutils::main::hba55c0d2a8f024e8
21:     0x560bfbe2f293 - std::sys_common::backtrace::__rust_begin_short_backtrace::h8924b28a3acc7439
22:     0x560bfbd7dea9 - std::rt::lang_start::{{closure}}::h7d241293ae4bf5d2
23:     0x560bfbffa174 - core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once::h45db14bcf775ab73
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/core/src/ops/function.rs:606:13
24:     0x560bfbffa174 - std::panicking::try::do_call::hf68ceb7f37b649c2
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panicking.rs:483:40
25:     0x560bfbffa174 - std::panicking::try::h6cf194e19ba51199
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panicking.rs:447:19
26:     0x560bfbffa174 - std::panic::catch_unwind::hd744b1dcd2d0b3b6
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panic.rs:137:14
27:     0x560bfbffa174 - std::rt::lang_start_internal::{{closure}}::h22311cdbdb8606d4
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/rt.rs:148:48
28:     0x560bfbffa174 - std::panicking::try::do_call::hf8f74cb16fd6f865
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panicking.rs:483:40
29:     0x560bfbffa174 - std::panicking::try::hd5fc8d0c36e286e2
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panicking.rs:447:19
30:     0x560bfbffa174 - std::panic::catch_unwind::hb795e28135635ab5
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panic.rs:137:14
31:     0x560bfbffa174 - std::rt::lang_start_internal::hea630cc8dcd1be35
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/rt.rs:148:20
32:     0x560bfbd91444 - main
33:     0x7fbee1342790 - <unknown>
34:     0x7fbee134284a - __libc_start_main
35:     0x560bfbd7b355 - _start
36:                0x0 - <unknown>

[sylvestre]

Do you have a way to reproduce it? thanks

[skbeh]

@sylvestre It panicks with most directories in my ccache directory, although the stats of the directory looks no difference with others.

[skbeh]

$ stat .cache/ccache/1
  File: .cache/ccache/1
  Size: 66              Blocks: 0          IO Block: 4096   directory
Device: 0,19    Inode: 1913861     Links: 1
Access: (0755/drwxr-xr-x)  Uid: ( 1000/    user)   Gid: ( 1000/    user)
Access: 2022-04-16 13:03:08.765480426 +0800
Modify: 2023-02-09 11:26:34.220614064 +0800
Change: 2023-02-09 11:26:34.220614064 +0800
 Birth: 1970-01-01 08:00:00.677852673 +0800

[sylvestre]

sccache/1 causes the issue ?

[skbeh]

@sylvestre I am not using sccache. I am using ccache.

[sylvestre]

sorry, typo, i was talking about the file anyway :)

[skbeh]

@sylvestre Not only /1, but also /3, /8 and something else.

[tertsdiepraam]

Could you maybe try again with a debug build so we get a more accurate backtrace?

[skbeh]

@tertsdiepraam

$ RUST_BACKTRACE=full target/debug/du ~/.cache/ccache/1
thread 'main' panicked at 'assertion failed: tv_nsec >= 0 && tv_nsec < NSEC_PER_SEC as i64', library/std/src/sys/unix/time.rs:66:9
stack backtrace:
0:     0x55782219022a - std::backtrace_rs::backtrace::libunwind::trace::h8705646449fcdebe
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/../../backtrace/src/backtrace/libunwind.rs:93:5
1:     0x55782219022a - std::backtrace_rs::backtrace::trace_unsynchronized::h28d01d89a8ff7fcd
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
2:     0x55782219022a - std::sys_common::backtrace::_print_fmt::h567dedd80dfd6cb4
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/sys_common/backtrace.rs:65:5
3:     0x55782219022a - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::haa2a40947cb119e8
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/sys_common/backtrace.rs:44:22
4:     0x5578221b187e - core::fmt::write::h3a707a9253e9c05a
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/core/src/fmt/mod.rs:1208:17
5:     0x55782218dcf3 - std::io::Write::write_fmt::h37756127f3897f3d
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/io/mod.rs:1682:15
6:     0x55782218fff5 - std::sys_common::backtrace::_print::he4d2e900b14c2d20
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/sys_common/backtrace.rs:47:5
7:     0x55782218fff5 - std::sys_common::backtrace::print::h7805ffe1784d912c
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/sys_common/backtrace.rs:34:9
8:     0x5578221919cf - std::panicking::default_hook::{{closure}}::h24b7e78ef7d394a7
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panicking.rs:267:22
9:     0x55782219170b - std::panicking::default_hook::hce783bd4bf40e7b5
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panicking.rs:286:9
10:     0x55782201d460 - <alloc::boxed::Box<F,A> as core::ops::function::Fn<Args>>::call::h2837fa93975e2156
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/alloc/src/boxed.rs:2032:9
11:     0x55782201be8f - uucore::mods::panic::mute_sigpipe_panic::{{closure}}::ha7799a8e782a4c23
at /home/user/.cache/paru/clone/coreutils-hybrid/src/coreutils-0.0.17/src/uucore/src/lib/mods/panic.rs:39:13
12:     0x5578221920fd - <alloc::boxed::Box<F,A> as core::ops::function::Fn<Args>>::call::h13b7b80bb8e26dbd
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/alloc/src/boxed.rs:2032:9
13:     0x5578221920fd - std::panicking::rust_panic_with_hook::heac8ae3e13a747ae
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panicking.rs:692:13
14:     0x557822191e32 - std::panicking::begin_panic_handler::{{closure}}::hc8562d54a563e54d
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panicking.rs:577:13
15:     0x5578221906ce - std::sys_common::backtrace::__rust_end_short_backtrace::h40df308e4f0a632a
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/sys_common/backtrace.rs:137:18
16:     0x557822191b82 - rust_begin_unwind
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panicking.rs:575:5
17:     0x557821fad963 - core::panicking::panic_fmt::h429554184794acce
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/core/src/panicking.rs:64:14
18:     0x557821fada3d - core::panicking::panic::h73760413ef6c70ee
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/core/src/panicking.rs:111:5
19:     0x55782218ad2d - std::sys::unix::time::Timespec::new::he9a7361562373a1e
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/sys/unix/time.rs:66:9
20:     0x55782218ad2d - std::sys::unix::time::SystemTime::new::h2dc7fd77f125d017
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/sys/unix/time.rs:29:25
21:     0x55782218ad2d - std::sys::unix::fs::FileAttr::created::h70dffb73be6eca36
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/sys/unix/fs.rs:485:24
22:     0x55782218ad2d - std::fs::Metadata::created::hbb83b0246866b1cf
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/fs.rs:1311:9
23:     0x557821fba93f - uu_du::birth_u64::h2ad24f197fa4a7b3
at /home/user/.cache/paru/clone/coreutils-hybrid/src/coreutils-0.0.17/src/uu/du/src/du.rs:188:5
24:     0x557821fba792 - uu_du::Stat::new::hd2dc74a3adeea6f3
at /home/user/.cache/paru/clone/coreutils-hybrid/src/coreutils-0.0.17/src/uu/du/src/du.rs:149:22
25:     0x557821fb617e - uu_du::uumain::uumain::h934fd2c42a5ec21a
at /home/user/.cache/paru/clone/coreutils-hybrid/src/coreutils-0.0.17/src/uu/du/src/du.rs:613:27
26:     0x557821fb4abc - uu_du::uumain::ha5431a94fcb00f61
at /home/user/.cache/paru/clone/coreutils-hybrid/src/coreutils-0.0.17/src/uu/du/src/du.rs:506:1
27:     0x557821fb2261 - du::main::hc013e4970d822130
at /home/user/.cache/paru/clone/coreutils-hybrid/src/coreutils-0.0.17/src/uucore/src/lib/lib.rs:91:24
28:     0x557821fb233b - core::ops::function::FnOnce::call_once::h959a6d76c1a37b32
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/core/src/ops/function.rs:507:5
29:     0x557821fb495e - std::sys_common::backtrace::__rust_begin_short_backtrace::ha958805e0584f607
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/sys_common/backtrace.rs:121:18
30:     0x557821fb4591 - std::rt::lang_start::{{closure}}::h8a9c4342ad617254
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/rt.rs:166:18
31:     0x557822189442 - core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once::h45db14bcf775ab73
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/core/src/ops/function.rs:606:13
32:     0x557822189442 - std::panicking::try::do_call::hf68ceb7f37b649c2
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panicking.rs:483:40
33:     0x557822189442 - std::panicking::try::h6cf194e19ba51199
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panicking.rs:447:19
34:     0x557822189442 - std::panic::catch_unwind::hd744b1dcd2d0b3b6
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panic.rs:137:14
35:     0x557822189442 - std::rt::lang_start_internal::{{closure}}::h22311cdbdb8606d4
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/rt.rs:148:48
36:     0x557822189442 - std::panicking::try::do_call::hf8f74cb16fd6f865
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panicking.rs:483:40
37:     0x557822189442 - std::panicking::try::hd5fc8d0c36e286e2
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panicking.rs:447:19
38:     0x557822189442 - std::panic::catch_unwind::hb795e28135635ab5
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panic.rs:137:14
39:     0x557822189442 - std::rt::lang_start_internal::hea630cc8dcd1be35
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/rt.rs:148:20
40:     0x557821fb456a - std::rt::lang_start::hd7a68a5994ccf979
at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/rt.rs:165:17
41:     0x557821fb22ce - main
42:     0x7f0e75c11790 - <unknown>
43:     0x7f0e75c1184a - __libc_start_main
44:     0x557821fadfd5 - _start
45:                0x0 - <unknown>

[tertsdiepraam]

Aha it's the birth_64 function that's causing the problem. Thanks!

The birth time here is unusually low:

Birth: 1970-01-01 08:00:00.677852673 +0800

[bast0006]

This appears to be a bug in the standard library (as it appears std::fs::Metadata::created is triggering the panic).

The panicking assertion is here:
https://github.com/rust-lang/rust/blob/a6975734632c4771edd45ef10e7d4753541d0f3a/library/std/src/sys/unix/time.rs#L69

The root cause seems to be the stat call returning a negative (pre-1970) birth time.

Can you provide more information on the system you're working with, like OSX vs linux, kernel version?

[skbeh]

I am using Arch Linux with kernel 6.1.10.

[bast0006]

What does stat /path/to/that/file and stat -r /path/to/file give you? Parsing (relatively speaking) of stat -f "%W" path is what appears to be exactly what is failing here

Or whatever incantation brings up btime through the raw stat command, as it varies a lot and I don't feel like digging through man pages any more for the exact command

[bast0006]

Right, you posted that up there, sorry. stat --terse /path/. What I/we want to see is the exact timestamp that stat is fetching, not the interpreted version.

[skbeh]

$ stat --terse .cache/ccache/1
.cache/ccache/1 66 0 41ed 1000 1000 13 1913861 1 0 0 1650085388 1676017866 1676017866 0 4096