open_ctree() took 228254398 us. And 98% of it that is 225418272 us
was taken by btrfs_read_block_groups().
-------------------
1) $ 225418272 us | } /* btrfs_read_block_groups [btrfs] */
1) * 16934.96 us | btrfs_check_rw_degradable [btrfs]();
0) 0.967 us | btrfs_apply_pending_changes [btrfs]();
0) 0.239 us | btrfs_read_qgroup_config [btrfs]();
0) * 21017.34 us | btrfs_get_root_ref [btrfs]();
0) + 15.717 us | btrfs_start_pre_rw_mount [btrfs]();
0) 0.865 us | btrfs_discard_resume [btrfs]();
0) $ 228254398 us | } /* open_ctree [btrfs] */
-------------------
Now we need to run the same thing on btrfs_read_block_groups(),
could you please run.. [1] (no need of the time).
[1]
$ umount /btrfs;
$./ftracegraph btrfs_read_block_groups 2 "*:mod:btrfs" "mount
/dev/vg/scratch0 /btrfs"
Thanks, Anand
On 30/08/2021 14:44, Jingyun He wrote:
Hi, Anand,
I have attached the new result.
Kindly check.
Thank you.
On Mon, Aug 30, 2021 at 9:27 AM Anand Jain [off-list ref] wrote:
quoted
Our open_ctree() took around ~223secs (~3.7mins)
1) $ 223375750 us | } /* open_ctree [btrfs] */
Unfortunately, the default trace buffer per CPU (4K) wasn't sufficient
and, the trace-buffer rolled over.
So we still don't know how long we spent in btrfs_read_block_groups().
Sorry for my mistake we should go 1 step at a time and, we have to do
this until we narrow it down to a specific function.
Could you please run with the depth = 2 (instead of 3) and use the time
command prefix. Also, pull a new ftracegraph as I have updated it to
display a proper time output.
$ ftracegraph open_ctree 2 "*:mod:btrfs" "time mount /dev/vg/scratch0
/btrfs"
Thanks, Anand
On 29/08/2021 17:42, Jingyun He wrote:
quoted
Hi, Anand
I have attached the file.
Could you kindly check this?
Thank you.
On Sun, Aug 29, 2021 at 7:47 AM Anand Jain [off-list ref] wrote:
quoted
On 28/08/2021 19:58, Jingyun He wrote:
quoted
Hello, all
I'm new to btrfs, I have a HM-SMR 14TB disk, I have formatted it to
btrfs to store the files.
When the device is almost full, it needs about 5 mins to mount the device.
Is it normal? is there any mount option that I can use to reduce the mount time?
We need to figure out the function taking a longer time (maybe it is
read-block-groups). I have similar reports on the non zoned device
as well (with a few TB full of data). But there is no good data yet
to analyse.
Could you please collect the trace data from the ftracegraph
from here [1] (It needs trace-cmd).
[1] https://github.com/asj/btrfstrace.git
Run it as in the example below:
umount /btrfs;
./ftracegraph open_ctree 3 "*:mod:btrfs" "mount /dev/vg/scratch0 /btrfs"
cat /tmp/ftracegraph.out
Thanks, Anand
open_ctree() took 228254398 us. And 98% of it that is 225418272 us
was taken by btrfs_read_block_groups().
-------------------
1) $ 225418272 us | } /* btrfs_read_block_groups [btrfs] */
1) * 16934.96 us | btrfs_check_rw_degradable [btrfs]();
0) 0.967 us | btrfs_apply_pending_changes [btrfs]();
0) 0.239 us | btrfs_read_qgroup_config [btrfs]();
0) * 21017.34 us | btrfs_get_root_ref [btrfs]();
0) + 15.717 us | btrfs_start_pre_rw_mount [btrfs]();
0) 0.865 us | btrfs_discard_resume [btrfs]();
0) $ 228254398 us | } /* open_ctree [btrfs] */
-------------------
Now we need to run the same thing on btrfs_read_block_groups(),
could you please run.. [1] (no need of the time).
[1]
$ umount /btrfs;
$./ftracegraph btrfs_read_block_groups 2 "*:mod:btrfs" "mount
/dev/vg/scratch0 /btrfs"
Thanks, Anand
Hi,
I also have a btrfs filesystem that takes a while to mount.
So I'm interested if this could be improved.
$ ./ftracegraph open_ctree 2 "*:mod:btrfs" "time mount /dev/md127 -o
space_cache=v2,compress=zstd,acl,subvol=Data /mnt/Data/"
kernel.ftrace_enabled = 1
real 1m33,638s
user 0m0,000s
sys 0m1,130s
Here's the trace output https://dāvis.lv/files/ftracegraph.out.gz
The filesystem is on top of RAID6 mdadm array which is from 9x 3TB HDDs.
Best regards,
Dāvis
open_ctree() took 228254398 us. And 98% of it that is 225418272 us
was taken by btrfs_read_block_groups().
-------------------
1) $ 225418272 us | } /* btrfs_read_block_groups [btrfs] */
1) * 16934.96 us | btrfs_check_rw_degradable [btrfs]();
0) 0.967 us | btrfs_apply_pending_changes [btrfs]();
0) 0.239 us | btrfs_read_qgroup_config [btrfs]();
0) * 21017.34 us | btrfs_get_root_ref [btrfs]();
0) + 15.717 us | btrfs_start_pre_rw_mount [btrfs]();
0) 0.865 us | btrfs_discard_resume [btrfs]();
0) $ 228254398 us | } /* open_ctree [btrfs] */
-------------------
Now we need to run the same thing on btrfs_read_block_groups(),
could you please run.. [1] (no need of the time).
[1]
$ umount /btrfs;
$./ftracegraph btrfs_read_block_groups 2 "*:mod:btrfs" "mount
/dev/vg/scratch0 /btrfs"
Thanks, Anand
Hi,
I also have a btrfs filesystem that takes a while to mount.
So I'm interested if this could be improved.
$ ./ftracegraph open_ctree 2 "*:mod:btrfs" "time mount /dev/md127 -o
space_cache=v2,compress=zstd,acl,subvol=Data /mnt/Data/"
It is better if we don't use the time prefix for the mount command
here. The ftrace, traces time syscall as well, which is unessential.
And we lose a lot of trace-buffer to it.
kernel.ftrace_enabled = 1
real 1m33,638s
user 0m0,000s
sys 0m1,130s
Here's the trace output https://dāvis.lv/files/ftracegraph.out.gz
The filesystem is on top of RAID6 mdadm array which is from 9x 3TB HDDs.
So here is a case of a non-zoned device.
Again it is btrfs_read_block_groups() which is taking ~98% of the time.
3) $ 91607669 us | } /* btrfs_read_block_groups [btrfs] */
3) # 9399.566 us | btrfs_check_rw_degradable [btrfs]();
3) 0.922 us | btrfs_apply_pending_changes [btrfs]();
3) ! 186.540 us | btrfs_read_qgroup_config [btrfs]();
3) * 26109.92 us | btrfs_get_root_ref [btrfs]();
3) + 23.965 us | btrfs_start_pre_rw_mount [btrfs]();
3) 1.192 us | btrfs_discard_resume [btrfs]();
3) $ 93501136 us | } /* open_ctree [btrfs] */
Could we pls get this?
$ ./ftracegraph btrfs_read_block_groups 2 "*:mod:btrfs" "mount ..."
Hopefully, there won't be a trace-buffer rollover here, as we saw in
the other case so that we could account for all the time spent.
Also, let's understand how many block groups are there.
$ btrfs in dump-tree <dev> | grep BLOCK_GROUP_ITEM | wc -l
Thx, Anand
open_ctree() took 228254398 us. And 98% of it that is 225418272 us
was taken by btrfs_read_block_groups().
-------------------
1) $ 225418272 us | } /* btrfs_read_block_groups [btrfs] */
As long as it's not zoned device, this is a known problem.
Block group items by its original design is scattered across the huge
extent tree.
Grabbing them all needs quite a lot of random IO, for large fs it's very
time consuming.
I have purposed a skinny bg tree design to put all block group items
into one tree, so that would greatly speed up the whole mount process.
And with user-space tool to do the convert.
But recently Josef is developing a completely new extent tree design,
which will include a similar design for it.
For know I'm not sure what's the way to go, either we can wait for
extent-tree-v2, or should we push for the middle ground skinny bg tree?
David, Any idea on this?
Thanks,
Qu
quoted
1) * 16934.96 us | btrfs_check_rw_degradable [btrfs]();
0) 0.967 us | btrfs_apply_pending_changes [btrfs]();
0) 0.239 us | btrfs_read_qgroup_config [btrfs]();
0) * 21017.34 us | btrfs_get_root_ref [btrfs]();
0) + 15.717 us | btrfs_start_pre_rw_mount [btrfs]();
0) 0.865 us | btrfs_discard_resume [btrfs]();
0) $ 228254398 us | } /* open_ctree [btrfs] */
-------------------
Now we need to run the same thing on btrfs_read_block_groups(),
could you please run.. [1] (no need of the time).
[1]
$ umount /btrfs;
$./ftracegraph btrfs_read_block_groups 2 "*:mod:btrfs" "mount
/dev/vg/scratch0 /btrfs"
Thanks, Anand
Hi,
I also have a btrfs filesystem that takes a while to mount.
So I'm interested if this could be improved.
$ ./ftracegraph open_ctree 2 "*:mod:btrfs" "time mount /dev/md127 -o
space_cache=v2,compress=zstd,acl,subvol=Data /mnt/Data/"
kernel.ftrace_enabled = 1
real 1m33,638s
user 0m0,000s
sys 0m1,130s
Here's the trace output https://dāvis.lv/files/ftracegraph.out.gz
The filesystem is on top of RAID6 mdadm array which is from 9x 3TB HDDs.
Best regards,
Dāvis
open_ctree() took 228254398 us. And 98% of it that is 225418272 us
was taken by btrfs_read_block_groups().
-------------------
1) $ 225418272 us | } /* btrfs_read_block_groups [btrfs] */
1) * 16934.96 us | btrfs_check_rw_degradable [btrfs]();
0) 0.967 us | btrfs_apply_pending_changes [btrfs]();
0) 0.239 us | btrfs_read_qgroup_config [btrfs]();
0) * 21017.34 us | btrfs_get_root_ref [btrfs]();
0) + 15.717 us | btrfs_start_pre_rw_mount [btrfs]();
0) 0.865 us | btrfs_discard_resume [btrfs]();
0) $ 228254398 us | } /* open_ctree [btrfs] */
-------------------
Now we need to run the same thing on btrfs_read_block_groups(),
could you please run.. [1] (no need of the time).
[1]
$ umount /btrfs;
$./ftracegraph btrfs_read_block_groups 2 "*:mod:btrfs" "mount
/dev/vg/scratch0 /btrfs"
Thanks, Anand
Hi,
I also have a btrfs filesystem that takes a while to mount.
So I'm interested if this could be improved.
$ ./ftracegraph open_ctree 2 "*:mod:btrfs" "time mount /dev/md127 -o
space_cache=v2,compress=zstd,acl,subvol=Data /mnt/Data/"
It is better if we don't use the time prefix for the mount command
here. The ftrace, traces time syscall as well, which is unessential.
And we lose a lot of trace-buffer to it.
quoted
kernel.ftrace_enabled = 1
real 1m33,638s
user 0m0,000s
sys 0m1,130s
Here's the trace output https://dāvis.lv/files/ftracegraph.out.gz
The filesystem is on top of RAID6 mdadm array which is from 9x 3TB HDDs.
So here is a case of a non-zoned device.
Again it is btrfs_read_block_groups() which is taking ~98% of the time.
3) $ 91607669 us | } /* btrfs_read_block_groups [btrfs] */
3) # 9399.566 us | btrfs_check_rw_degradable [btrfs]();
3) 0.922 us | btrfs_apply_pending_changes [btrfs]();
3) ! 186.540 us | btrfs_read_qgroup_config [btrfs]();
3) * 26109.92 us | btrfs_get_root_ref [btrfs]();
3) + 23.965 us | btrfs_start_pre_rw_mount [btrfs]();
3) 1.192 us | btrfs_discard_resume [btrfs]();
3) $ 93501136 us | } /* open_ctree [btrfs] */
Could we pls get this?
$ ./ftracegraph btrfs_read_block_groups 2 "*:mod:btrfs" "mount ..."
Hopefully, there won't be a trace-buffer rollover here, as we saw in
the other case so that we could account for all the time spent.
On 02/09/2021 00:11, Dāvis Mosāns wrote:
pirmd., 2021. g. 30. aug., plkst. 16:08 — lietotājs Anand Jain
([off-list ref]) rakstīja:
open_ctree() took 228254398 us. And 98% of it that is 225418272 us
was taken by btrfs_read_block_groups().
-------------------
1) $ 225418272 us | } /* btrfs_read_block_groups [btrfs] */
1) * 16934.96 us | btrfs_check_rw_degradable [btrfs]();
0) 0.967 us | btrfs_apply_pending_changes [btrfs]();
0) 0.239 us | btrfs_read_qgroup_config [btrfs]();
0) * 21017.34 us | btrfs_get_root_ref [btrfs]();
0) + 15.717 us | btrfs_start_pre_rw_mount [btrfs]();
0) 0.865 us | btrfs_discard_resume [btrfs]();
0) $ 228254398 us | } /* open_ctree [btrfs] */
-------------------
Now we need to run the same thing on btrfs_read_block_groups(),
could you please run.. [1] (no need of the time).
[1]
$ umount /btrfs;
$./ftracegraph btrfs_read_block_groups 2 "*:mod:btrfs" "mount
/dev/vg/scratch0 /btrfs"
Thanks, Anand
Hi,
I also have a btrfs filesystem that takes a while to mount.
So I'm interested if this could be improved.
$ ./ftracegraph open_ctree 2 "*:mod:btrfs" "time mount /dev/md127 -o
space_cache=v2,compress=zstd,acl,subvol=Data /mnt/Data/"
It is better if we don't use the time prefix for the mount command
here. The ftrace, traces time syscall as well, which is unessential.
And we lose a lot of trace-buffer to it.
kernel.ftrace_enabled = 1
real 1m33,638s
user 0m0,000s
sys 0m1,130s
Here's the trace output https://dāvis.lv/files/ftracegraph.out.gz
The filesystem is on top of RAID6 mdadm array which is from 9x 3TB HDDs.
So here is a case of a non-zoned device.
Again it is btrfs_read_block_groups() which is taking ~98% of the time.
3) $ 91607669 us | } /* btrfs_read_block_groups [btrfs] */
3) # 9399.566 us | btrfs_check_rw_degradable [btrfs]();
3) 0.922 us | btrfs_apply_pending_changes [btrfs]();
3) ! 186.540 us | btrfs_read_qgroup_config [btrfs]();
3) * 26109.92 us | btrfs_get_root_ref [btrfs]();
3) + 23.965 us | btrfs_start_pre_rw_mount [btrfs]();
3) 1.192 us | btrfs_discard_resume [btrfs]();
3) $ 93501136 us | } /* open_ctree [btrfs] */
Could we pls get this?
$ ./ftracegraph btrfs_read_block_groups 2 "*:mod:btrfs" "mount ..."
Hopefully, there won't be a trace-buffer rollover here, as we saw in
the other case so that we could account for all the time spent.
Also, let's understand how many block groups are there.
$ btrfs in dump-tree <dev> | grep BLOCK_GROUP_ITEM | wc -l
It's 22660
Also by the way `-t EXTENT_TREE` should be faster
Just to add more data, I have a 10-device raid1 array with ~86TB used.
My results:
root@SERVER:~# btrfs in dump-tree -t EXTENT_TREE /dev/sdf | grep BLOCK_GROUP_ITEM | wc -l
44986
I estimate it takes ~83 seconds to mount. (by looking at dmesg) It sometimes times out on boot and drops to recovery mode, as systemd will only wait 90 seconds, and for some reason 'x-systemd.mount-timeout=500' doesn't work
Note that I defragment the subvolume and extent tree for each subvolume weekly, as it seems to reduce my mount times, and make it *usually* boot without dropping to recovery mode.
--Joshua
open_ctree() took 228254398 us. And 98% of it that is 225418272 us
was taken by btrfs_read_block_groups().
-------------------
1) $ 225418272 us | } /* btrfs_read_block_groups [btrfs] */
1) * 16934.96 us | btrfs_check_rw_degradable [btrfs]();
0) 0.967 us | btrfs_apply_pending_changes [btrfs]();
0) 0.239 us | btrfs_read_qgroup_config [btrfs]();
0) * 21017.34 us | btrfs_get_root_ref [btrfs]();
0) + 15.717 us | btrfs_start_pre_rw_mount [btrfs]();
0) 0.865 us | btrfs_discard_resume [btrfs]();
0) $ 228254398 us | } /* open_ctree [btrfs] */
-------------------
Now we need to run the same thing on btrfs_read_block_groups(),
could you please run.. [1] (no need of the time).
[1]
$ umount /btrfs;
$./ftracegraph btrfs_read_block_groups 2 "*:mod:btrfs" "mount
/dev/vg/scratch0 /btrfs"
Thanks, Anand
Hi,
I also have a btrfs filesystem that takes a while to mount.
So I'm interested if this could be improved.
$ ./ftracegraph open_ctree 2 "*:mod:btrfs" "time mount /dev/md127 -o
space_cache=v2,compress=zstd,acl,subvol=Data /mnt/Data/"
It is better if we don't use the time prefix for the mount command
here. The ftrace, traces time syscall as well, which is unessential.
And we lose a lot of trace-buffer to it.
quoted
kernel.ftrace_enabled = 1
real 1m33,638s
user 0m0,000s
sys 0m1,130s
Here's the trace output https://dāvis.lv/files/ftracegraph.out.gz
The filesystem is on top of RAID6 mdadm array which is from 9x 3TB HDDs.
So here is a case of a non-zoned device.
Again it is btrfs_read_block_groups() which is taking ~98% of the time.
3) $ 91607669 us | } /* btrfs_read_block_groups [btrfs] */
3) # 9399.566 us | btrfs_check_rw_degradable [btrfs]();
3) 0.922 us | btrfs_apply_pending_changes [btrfs]();
3) ! 186.540 us | btrfs_read_qgroup_config [btrfs]();
3) * 26109.92 us | btrfs_get_root_ref [btrfs]();
3) + 23.965 us | btrfs_start_pre_rw_mount [btrfs]();
3) 1.192 us | btrfs_discard_resume [btrfs]();
3) $ 93501136 us | } /* open_ctree [btrfs] */
Could we pls get this?
$ ./ftracegraph btrfs_read_block_groups 2 "*:mod:btrfs" "mount ..."
Hopefully, there won't be a trace-buffer rollover here, as we saw in
the other case so that we could account for all the time spent.