Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
Message-ID: <21dd32c6-f1f9-f44a-466a-e18fdc6788a7@virtuozzo.com>
Date:   Thu, 4 Aug 2022 19:30:52 +0300
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:91.0) Gecko/20100101
 Thunderbird/91.10.0
Content-Language: en-US
To:     Chris Mason <clm@fb.com>, Josef Bacik <josef@toxicpanda.com>,
        David Sterba <dsterba@suse.com>
Cc:     linux-btrfs@vger.kernel.org, lkml <linux-kernel@vger.kernel.org>,
        Chen Liang-Chun <featherclc@gmail.com>,
        Alexander Mikhalitsyn <alexander.mikhalitsyn@virtuozzo.com>,
        kernel@openvz.org,
        Dominique MARTINET <dominique.martinet@atmark-techno.com>,
        Yu Kuai <yukuai3@huawei.com>, Theodore Ts'o <tytso@mit.edu>
From:   Pavel Tikhomirov <ptikhomirov@virtuozzo.com>
Subject: fiemap is slow on btrfs on files with multiple extents
Content-Type: text/plain; charset=UTF-8; format=flowed
Content-Transfer-Encoding: 7bit
MIME-Version: 1.0
X-MS-Exchange-AntiSpam-MessageData-ChunkCount: 1
X-MS-Exchange-AntiSpam-MessageData-0: =?utf-8?B?a01FZ09DWFZYanlINzBDaldnNm9JdE5jcFh3dXp6Zmw0WGhrSHhMUzFFU21p?=
 =?utf-8?B?dG5FaXYrU04rU1RkQzErV2xOZEZZQlBUWkhxc25ONHFJTDdqYjZRQ3ZscTdq?=
 =?utf-8?B?aXR2Z2E4bmZRYy91VFZBYkFRWWNpRmN6bjY2SkRYMHl0QTRSeFZYM0FXakxC?=
 =?utf-8?B?U3BRR01lRFBEbzlVSjljcE55V3F3TXIvRUJZNXloTDVicE5ieUFsL0J6Wmxr?=
 =?utf-8?B?Ti9JT1dJNmh6aGExWFVOSnFGdG50SGNWZFVKVko5ZVpJbzJybXNyUHczSXpM?=
 =?utf-8?B?NG9Da1RubXd2aFVkVndFbmowZ3R1QVczc004enpyVUFuNnd0bTRQV2lmdzNV?=
 =?utf-8?B?cEVWS3dlaW5rOVV6eGQwNEl1T0d0TldaL0Voc3dTdE04NGFPeFhGZy9OK0Fq?=
 =?utf-8?B?M0FRMjdwWHNQWWErcGNzRnUzRnZoZDFqZXBySU8wSnl4dnNTSXhIZzVrVG51?=
 =?utf-8?B?THpPZUlSUndMVmRnY3ZLSUtJaWNLSUU4dklKWjduYi9URVFXdXR2bCtHNzYz?=
 =?utf-8?B?VXRpaEVOc1JwbXN0NGxvY2R0R2F1eTFmRXRRRFFlYThDbE0rN1Q4aHNzU3Nm?=
 =?utf-8?B?RkxmWEhUNW9Lc2NaK2VWQ3hzbmEwaGFaR01qSVdNVlByVE5aY3p3SVZuL1NL?=
 =?utf-8?B?R0pEUFF1a0xEZ29EM3MyZ1V6NG5Ib1pGb0p6YlQzLzRrcDJNd0VFTmRDWkFo?=
 =?utf-8?B?eVhjcjhnR1gwQ3huaTcwOHNldDRFTW9waEFZSTZnWW5JK29WbzFCQXV4V0dG?=
 =?utf-8?B?bUFGTWdzbzZZalpyM1Z4UVdPcCtJYmN2Q1RRZCtHWDVGdVRjcXBsTmk4RTdz?=
 =?utf-8?B?NGdCeENTZHpnQW5lazF5Z0R3M2kwSWtxRGVpV2FBZjRsaFk1YmpGdzUvRi9X?=
 =?utf-8?B?Y25BVnVlNGNYbW1tR2xsaXRqYU12T3Fsc3crTW9vaFlpZi9Yc2dHMWptUU9P?=
 =?utf-8?B?UTBXYVQxam9oNGxvNkhXbFhGekVaclBpRWMxaDdRcFdiN3UvcVF2emRvalpa?=
 =?utf-8?B?OS9ISHkrRWV1ZDUvOVhrSHpVTlNia2pqUnpVMkNUUEJQMG9jQi9aME12K01m?=
 =?utf-8?B?ZzdhZ1NDdkNXU202d0xRV0I1d3cvYWJFWVhwc21DdThZYnp3NkpmclBSSDEw?=
 =?utf-8?B?UlhzYzg4TnNPcDlZWDFvdHkrcjBGNThlZjlQZDViWWJHV1lpUzBrM3NDelZz?=
 =?utf-8?B?Rk1ocm5OdGFmS0hUQVk3ZXhBRExXMzhWOTRwR1piclYrdm9MYm4rL2ZzaFgv?=
 =?utf-8?B?bEhZanRLaGlsUmJXVkhBdExIRkRUVnJRS1l2dXJ4eDFzQTRoUVFqN1VnYnZn?=
 =?utf-8?B?c1Jnd2VWcmY1QmRaV1lvZVFMOG8yZHNXL0FLZDFkUXFabXd5ekxzODdTTHV3?=
 =?utf-8?B?b1VZTStpdFJmaVNWVDlvV2VQOHh1Q1kvYXp4V2VQUDlaWnlWUW1iZEU3aEE4?=
 =?utf-8?B?T05QMDM2MUZQY0J4Y1g2OHQxbXNrQW1VSEEzZDBjeWw5RmdMNjlnTk1zRGt2?=
 =?utf-8?B?RHR6cGV0VCt2REhJSGRoMW9FQkxUcVZTVFBUbXhacmVycFQ2ckIrNGt3VmVy?=
 =?utf-8?B?TWpWdWZvMjl3MkgrNkhHZFNUUWI3S1k5T2hJZGo1L21qSUlpZ3dlWGw0aWhR?=
 =?utf-8?B?bHhYQUZKS21NZGFhUTQ5ODNrYU1DTUhDV3RjZmNwd081Sm1iZlNLR2M2SEhI?=
 =?utf-8?B?RUkxZXZTWGE3cUVzeWJwTndyVzJjUG5Xay9NOXJXT2V5elJJVXlHZVo1NG1J?=
 =?utf-8?B?QkJ2RjFxcUIrRkI2aDNsN3hmY0wzay9yNjBVTXB3WHVLVU0xYk1xclJqTGVk?=
 =?utf-8?B?dFd1TXhmNUwrM2tpUGJabjJaY1YyeW5JRVJhSjcwQlhiK2c4NnlTRS9pY0FW?=
 =?utf-8?B?YWlpTFMvSktwS0s4UW5ZZ0lzNlFlVzhVamNMYVJ3MHZnbEhGWDJuSmE0VDBt?=
 =?utf-8?B?MUdCL2Era0hxdXBYQW00L3BBdGhVU1JJUS90UDd6R2NLamg0L0RmWllqY3NQ?=
 =?utf-8?B?Q0JQSW5XTzBnczhwclY5VXRxQm1Xd0doMHJLdUlZL2p4N1BoVHZwZ2dyck5T?=
 =?utf-8?B?MVJUWDhXTnltSjRKY05QTVQ4R1IxUTFPeEQrbXJlTHZ5ZVI2TWZDNlc4a0tQ?=
 =?utf-8?B?UW8vWlE1TDN6aWVXd1hOZHdHMzJhY3RkQm5KODcrVUJzQ2c5UTNyTmlDeHVx?=
 =?utf-8?B?YXc9PQ==?=
X-OriginatorOrg: virtuozzo.com
X-MS-Exchange-CrossTenant-Network-Message-Id: b635fa31-71e1-471f-0d03-08da7636b45f
X-MS-Exchange-CrossTenant-AuthSource: VE1PR08MB4989.eurprd08.prod.outlook.com
X-MS-Exchange-CrossTenant-AuthAs: Internal
X-MS-Exchange-CrossTenant-OriginalArrivalTime: 04 Aug 2022 16:30:55.4036
 (UTC)
X-MS-Exchange-CrossTenant-FromEntityHeader: Hosted
X-MS-Exchange-CrossTenant-Id: 0bc7f26d-0264-416e-a6fc-8352af79c58f
X-MS-Exchange-CrossTenant-MailboxType: HOSTED
X-MS-Exchange-CrossTenant-UserPrincipalName: OtGR2VtQB9hNplX2K+RW2KeIlgPYOy0YRJ5A291XdRBapoCIMxYZyi5zZEP07kG55h+rx/fR4nqiDLuWrwSY8kEaBS5Wgf6e8q6Y2a18ypE=
X-MS-Exchange-Transport-CrossTenantHeadersStamped: PAXPR08MB7060
X-Spam-Status: No, score=-1.1 required=5.0 tests=BAYES_00,DKIM_SIGNED,
        DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,FORGED_SPF_HELO,
        RCVD_IN_DNSWL_NONE,RCVD_IN_MSPIKE_H2,SPF_HELO_PASS,SPF_NONE
        autolearn=no autolearn_force=no version=3.4.6
X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on
        lindbergh.monkeyblade.net
Precedence: bulk
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org

I ran the below test on Fedora 36 (the test basically creates "very" 
sparse file, with 4k data followed by 4k hole again and again for the 
specified length and uses fiemap to count extents in this file) and face 
the problem that fiemap hangs for too long (for instance comparing to 
ext4 version). Fiemap with 32768 extents takes ~37264 us and with 65536 
extents it takes ~34123954 us, which is x1000 times more when file only 
increased twice the size:

256Mb:

./fiemap-reproduce /testfile $((1<<28))
size: 268435456
actual size: 134217728
fiemap: fm_mapped_extents = 32768
time = 37264 us

./fiemap-reproduce /testfile $((1<<28))
size: 268435456
actual size: 134217728
fiemap: fm_mapped_extents = 32768
time = 37285 us

512Mb:

./fiemap-reproduce /testfile $((1<<29))
size: 536870912
actual size: 268435456
fiemap: fm_mapped_extents = 65536
time = 34123954 us

./fiemap-reproduce /testfile $((1<<29))
size: 536870912
actual size: 268435456
fiemap: fm_mapped_extents = 65536
time = 60404334 us

1Gb (the whole Fedora hangs sometimes when I measure it):

./fiemap-reproduce /testfile $((1<<30))
size: 1073741824
actual size: 536870912
fiemap: fm_mapped_extents = 131072
time = 231194793 us

./fiemap-reproduce /testfile $((1<<30))
size: 1073741824
actual size: 536870912
fiemap: fm_mapped_extents = 131072
time = 347867789 us

I see a similar problem here 
https://lore.kernel.org/linux-btrfs/Yr4nEoNLkXPKcOBi@atmark-techno.com/#r , 
but in my case I have "5.18.6-200.fc36.x86_64" fedora kernel which does 
not have 5ccc944dce3d ("filemap: Correct the conditions for marking a 
folio as accessed") commit, so it should be something else.

Some more info:

cat /proc/self/mountinfo | grep btrfs
106 1 0:47 /root / rw,relatime shared:1 - btrfs /dev/nvme0n1p3 
rw,compress=zstd:1,ssd,space_cache,subvolid=257,subvol=/root

perf top -ag
Samples: 268K of event 'cycles', 4000 Hz, Event count (approx.): 
77250404934 lost: 0/0 drop: 0/0
   Children      Self  Shared Object                       Symbol
+   74,25%     1,16%  [kernel]                            [k] 
entry_SYSCALL_64_after_hwframe
+   73,14%     0,65%  [kernel]                            [k] do_syscall_64
+   53,05%     3,30%  libc.so.6                           [.] __poll
+   39,53%     0,76%  [kernel]                            [k] __x64_sys_poll
+   34,91%     6,44%  [kernel]                            [k] do_sys_poll
+   29,37%     0,00%  [kernel]                            [k] 
__x64_sys_ioctl
+   29,08%     7,65%  [kernel]                            [k] 
count_range_bits
+   28,44%     0,00%  [kernel]                            [k] do_vfs_ioctl
+   28,43%     0,00%  [kernel]                            [k] extent_fiemap
+   28,43%     0,00%  [kernel]                            [k] 
btrfs_get_extent_fiemap
+   27,87%     0,00%  libc.so.6                           [.] __GI___ioctl
+   25,89%     0,00%  [kernel]                            [k] 
get_extent_skip_holes
+   21,76%    21,29%  [kernel]                            [k] rb_next
+    9,50%     0,48%  [kernel]                            [k] perf_poll
+    8,04%     0,00%  libc.so.6                           [.] 
__libc_start_call_main
+    6,93%     3,26%  [kernel]                            [k] 
select_estimate_accuracy
+    6,69%     2,15%  [kernel]                            [k] ktime_get_ts64
+    5,60%     3,99%  [kernel]                            [k] 
_raw_spin_lock_irqsave
+    5,16%     0,40%  [kernel]                            [k] poll_freewait

Here is a fiemap-reproduce.c code:

#include <stdio.h>
#include <unistd.h>
#include <stdlib.h>
#include <fcntl.h>

#include <sys/stat.h>
#include <sys/time.h>
#include <sys/ioctl.h>

#include <linux/fs.h>
#include <linux/fiemap.h>

#define FILE_INTERVAL (1<<13) /* 8Kb */

long long interval(struct timeval t1, struct timeval t2)
{
         long long val = 0;
         val += (t2.tv_usec - t1.tv_usec);
         val += (t2.tv_sec - t1.tv_sec) * 1000 * 1000;
         return val;
}

int main(int argc, char **argv) {
         struct fiemap fiemap = {};
         struct timeval t1, t2;
         char data = 'a';
         struct stat st;
         int fd, off, file_size = FILE_INTERVAL;

         if (argc != 3 && argc != 2) {
                 printf("usage: %s <path> [size]\n", argv[0]);
                 return 1;
         }

         if (argc == 3)
                 file_size = atoi(argv[2]);
         if (file_size < FILE_INTERVAL)
                 file_size = FILE_INTERVAL;
         file_size -= file_size % FILE_INTERVAL;

         fd = open(argv[1], O_RDWR | O_CREAT | O_TRUNC, 0644);
         if (fd < 0) {
                 perror("open");
                 return 1;
         }

         for (off = 0; off < file_size; off += FILE_INTERVAL) {
                 if (pwrite(fd, &data, 1, off) != 1) {
                         perror("pwrite");
                         close(fd);
                         return 1;
                 }
         }

         if (ftruncate(fd, file_size)) {
                 perror("ftruncate");
                 close(fd);
                 return 1;
         }

         if (fstat(fd, &st) < 0) {
                 perror("fstat");
                 close(fd);
                 return 1;
         }

         printf("size: %ld\n", st.st_size);
         printf("actual size: %ld\n", st.st_blocks * 512);

         fiemap.fm_length = FIEMAP_MAX_OFFSET;
         gettimeofday(&t1, NULL);
         if (ioctl(fd, FS_IOC_FIEMAP, &fiemap) < 0) {
                 perror("fiemap");
                 close(fd);
                 return 1;
         }
         gettimeofday(&t2, NULL);

         printf("fiemap: fm_mapped_extents = %d\n", 
fiemap.fm_mapped_extents);
         printf("time = %lld us\n", interval(t1, t2));

         close(fd);
         return 0;
}

-- 
Best regards, Tikhomirov Pavel
Software Developer, Virtuozzo.