Potentially wasted space when storing chunk files on Btrfs

What did you do?

Ran Prometheus in a container using Podman and a Btrfs volume for storage.

$ podman run --name prometheus_test --net host -v prometheus_test:/prometheus:Z -v /home/$USER/config.yml:/prometheus/prometheus.yml prometheus

What did you expect to see?

A lower disk usage than 256M for every chunk file.

What did you see instead? Under which circumstances?

A disk usage of precisely 256M for every chunk file (as reported by compsize).

$ ls -l /home/$USER/.local/share/containers/storage/volumes/prometheus_test/_data/
total 4
drwxr-xr-x. 1 165533 165533    60 Jul 21 03:43 01FB3BPMXJ9HH7KS5AKV5HCNYY
drwxr-xr-x. 1 165533 165533    60 Jul 21 05:00 01FB3G3MMMY0TB7WWMBJWR1KZY
drwxr-xr-x. 1 165533 165533    60 Jul 21 07:00 01FB3PZBWMNTTVEG5NA41D83BJ
drwxr-xr-x. 1 165533 165533    60 Jul 21 09:00 01FB3XV34K0WNACCYBYCD6Q4AR
drwxr-xr-x. 1 165533 165533    60 Jul 21 11:00 01FB44PTCGS3RKG2K8K2PQRSJX
drwxr-xr-x. 1 165533 165533    24 Jul 21 11:00 chunks_head
-rw-r--r--. 1 165533 165533     0 Jul 21 00:42 lock
-rwx------. 1 curry  curry      0 Jul 21 00:42 prometheus.yml
-rw-r--r--. 1 165533 165533 20001 Jul 21 00:42 queries.active
drwxr-xr-x. 1 165533 165533   102 Jul 21 11:00 wal

$ ls -l /home/$USER/.local/share/containers/storage/volumes/prometheus_test/_data/01FB3XV34K0WNACCYBYCD6Q4AR/chunks
total 200
-rw-r--r--. 1 165533 165533 204698 Jul 21 09:00 000001

$ sudo compsize /home/$USER/.local/share/containers/storage/volumes/prometheus_test/_data/01FB3XV34K0WNACCYBYCD6Q4AR
/chunks/000001 
Processed 1 file, 1 regular extents (1 refs), 0 inline.
Type       Perc     Disk Usage   Uncompressed Referenced  
TOTAL      100%      256M         256M         200K       
none       100%      256M         256M         200K

$ ls -l /home/$USER/.local/share/containers/storage/volumes/prometheus_test/_data/01FB44PTCGS3RKG2K8K2PQRSJX/chunks
total 196
-rw-r--r--. 1 165533 165533 198213 Jul 21 11:00 000001

$ sudo compsize /home/$USER/.local/share/containers/storage/volumes/prometheus_test/_data/01FB44PTCGS3RKG2K8K2PQRSJX/chunks/000001 
Processed 1 file, 1 regular extents (1 refs), 0 inline.
Type       Perc     Disk Usage   Uncompressed Referenced  
TOTAL      100%      256M         256M         196K       
none       100%      256M         256M         196K 

Environment

Running

• System information:

$ uname -srm
Linux 5.12.15-300.fc34.x86_64 x86_64

• Prometheus version:

$ podman run --rm prometheus --version
prometheus, version 2.28.1 (branch: HEAD, revision: b0944590a1c9a6b35dc5a696869f75f422b107a1)
  build user:       root@2915dd495090
  build date:       20210701-15:20:10
  go version:       go1.16.5
  platform:         linux/amd64

• Prometheus configuration file:

global:
  scrape_interval: 15s

scrape_configs:
  - job_name: 'localhost'
    static_configs:
      - targets: ['localhost:9100']

• Logs:

podman run --name prometheus_test --net host -v prometheus_test:/prometheus:Z -v /home/curry/config.yml:/prometheus/prometheus.yml:Z prometheus
level=info ts=2021-07-20T22:42:51.543Z caller=main.go:389 msg="No time or size retention was set so using the default time retention" duration=15d
level=info ts=2021-07-20T22:42:51.543Z caller=main.go:443 msg="Starting Prometheus" version="(version=2.28.1, branch=HEAD, revision=b0944590a1c9a6b35dc5a696869f75f422b107a1)"
level=info ts=2021-07-20T22:42:51.543Z caller=main.go:448 build_context="(go=go1.16.5, user=root@2915dd495090, date=20210701-15:20:10)"
level=info ts=2021-07-20T22:42:51.543Z caller=main.go:449 host_details="(Linux 5.12.15-300.fc34.x86_64 #1 SMP Wed Jul 7 19:46:50 UTC 2021 x86_64 passionator (none))"
level=info ts=2021-07-20T22:42:51.543Z caller=main.go:450 fd_limits="(soft=524288, hard=524288)"
level=info ts=2021-07-20T22:42:51.543Z caller=main.go:451 vm_limits="(soft=unlimited, hard=unlimited)"
level=info ts=2021-07-20T22:42:51.545Z caller=web.go:541 component=web msg="Start listening for connections" address=0.0.0.0:9090
level=info ts=2021-07-20T22:42:51.545Z caller=main.go:824 msg="Starting TSDB ..."
level=info ts=2021-07-20T22:42:51.547Z caller=tls_config.go:191 component=web msg="TLS is disabled." http2=false
level=info ts=2021-07-20T22:42:51.548Z caller=head.go:780 component=tsdb msg="Replaying on-disk memory mappable chunks if any"
level=info ts=2021-07-20T22:42:51.548Z caller=head.go:794 component=tsdb msg="On-disk memory mappable chunks replay completed" duration=1.869µs
level=info ts=2021-07-20T22:42:51.548Z caller=head.go:800 component=tsdb msg="Replaying WAL, this may take a while"
level=info ts=2021-07-20T22:42:51.549Z caller=head.go:854 component=tsdb msg="WAL segment loaded" segment=0 maxSegment=0
level=info ts=2021-07-20T22:42:51.549Z caller=head.go:860 component=tsdb msg="WAL replay completed" checkpoint_replay_duration=22.633µs wal_replay_duration=182.827µs total_replay_duration=219.49µs
level=info ts=2021-07-20T22:42:51.550Z caller=main.go:851 fs_type=9123683e
level=info ts=2021-07-20T22:42:51.550Z caller=main.go:854 msg="TSDB started"
level=info ts=2021-07-20T22:42:51.550Z caller=main.go:981 msg="Loading configuration file" filename=/etc/prometheus/prometheus.yml
level=info ts=2021-07-20T22:42:51.550Z caller=main.go:1012 msg="Completed loading of configuration file" filename=/etc/prometheus/prometheus.yml totalDuration=680.073µs remote_storage=1.222µs web_handler=243ns query_engine=653ns scrape=371.624µs scrape_sd=28.4µs notify=17.267µs notify_sd=8.621µs rules=930ns
level=info ts=2021-07-20T22:42:51.550Z caller=main.go:796 msg="Server is ready to receive web requests."
level=info ts=2021-07-21T01:43:23.335Z caller=compact.go:518 component=tsdb msg="write block" mint=1626820988306 maxt=1626825600000 ulid=01FB3BPMXJ9HH7KS5AKV5HCNYY duration=21.06348ms
level=info ts=2021-07-21T01:43:23.336Z caller=head.go:967 component=tsdb msg="Head GC completed" duration=950.267µs
level=info ts=2021-07-21T03:00:23.368Z caller=compact.go:518 component=tsdb msg="write block" mint=1626825608306 maxt=1626832800000 ulid=01FB3G3MMMY0TB7WWMBJWR1KZY duration=52.575503ms
level=info ts=2021-07-21T03:00:23.370Z caller=head.go:967 component=tsdb msg="Head GC completed" duration=949.16µs
level=info ts=2021-07-21T05:00:23.357Z caller=compact.go:518 component=tsdb msg="write block" mint=1626832808306 maxt=1626840000000 ulid=01FB3PZBWMNTTVEG5NA41D83BJ duration=40.943109ms
level=info ts=2021-07-21T05:00:23.358Z caller=head.go:967 component=tsdb msg="Head GC completed" duration=959.689µs
level=info ts=2021-07-21T07:00:23.414Z caller=compact.go:518 component=tsdb msg="write block" mint=1626840008306 maxt=1626847200000 ulid=01FB3XV34K0WNACCYBYCD6Q4AR duration=98.595624ms
level=info ts=2021-07-21T07:00:23.415Z caller=head.go:967 component=tsdb msg="Head GC completed" duration=921.802µs
level=info ts=2021-07-21T07:00:23.418Z caller=checkpoint.go:97 component=tsdb msg="Creating checkpoint" from_segment=0 to_segment=1 mint=1626847200000
level=info ts=2021-07-21T07:00:23.436Z caller=head.go:1064 component=tsdb msg="WAL checkpoint complete" first=0 last=1 duration=17.954747ms
level=info ts=2021-07-21T09:00:23.391Z caller=compact.go:518 component=tsdb msg="write block" mint=1626847208306 maxt=1626854400000 ulid=01FB44PTCGS3RKG2K8K2PQRSJX duration=78.676554ms
level=info ts=2021-07-21T09:00:23.392Z caller=head.go:967 component=tsdb msg="Head GC completed" duration=915.667µs

Misc comments/thoughts/suspicions

Could this be an issue with too aggressive fallocate calls? However, I think if that is the case, compsize should report some of the 256M as pre-allocated, which it does not. I would do a bit more digging in the code but I'm not too well versed in either Go or this project.