slow bd_fs_ntfs_get_info causing timeouts to udisks2 clients and hanging KDE about libblockdev

[amurzeau]

Hi again,

I've tried a quick patch and it fixes the issue for me.
The reported size is correct (but I don't know how to get the free space size from udisksctl, but Dolphin shows something good for the disk usage blue bar).

The maximum udisksctl status execution time I get while plugging in my USB key is 0.9s.
Maybe this can be further improved, but at least udisks2 doesn't hang and cause timeouts :)

From: Alexis Murzeau <[email protected]>
Date: Fri, 14 Jul 2023 14:52:28 +0000
Subject: Use ntfsinfo instead of ntfscluster for faster bd_fs_ntfs_get_info

ntfscluster can take as much as 45s to complete on a USB key.

Use ntfsinfo to get size information instead of ntfscluster, ntfsinfo
is near instantanous (177ms instead of 45s on the same USB key).

Signed-off-by: Alexis Murzeau <[email protected]>
---
 src/plugins/fs/generic.c    |  2 +-
 src/plugins/fs/ntfs.c       | 44 ++++++++++++++++++++++++++++++++------------
 tests/fs_tests/ntfs_test.py |  6 +++---
 tests/utils.py              |  2 +-
 4 files changed, 37 insertions(+), 17 deletions(-)

diff --git a/src/plugins/fs/generic.c b/src/plugins/fs/generic.c
index 4406d5c..075af7e 100644
--- a/src/plugins/fs/generic.c
+++ b/src/plugins/fs/generic.c
@@ -229,7 +229,7 @@ const BDFSInfo fs_info[BD_FS_LAST_FS] = {
       .repair_util = "ntfsfix",
       .resize_util = "ntfsresize",
       .label_util = "ntfslabel",
-      .info_util = "ntfscluster",
+      .info_util = "ntfsinfo",
       .uuid_util = "ntfslabel" },
     /* F2FS */
     { .type = "f2fs",
diff --git a/src/plugins/fs/ntfs.c b/src/plugins/fs/ntfs.c
index 517d1cf..1aa503c 100644
--- a/src/plugins/fs/ntfs.c
+++ b/src/plugins/fs/ntfs.c
@@ -20,6 +20,7 @@
 #include <blockdev/utils.h>
 #include <check_deps.h>
 #include <string.h>
+#include <stdio.h>
 
 #include "ntfs.h"
 #include "fs.h"
@@ -36,8 +37,8 @@ static GMutex deps_check_lock;
 #define DEPS_NTFSRESIZE_MASK (1 << DEPS_NTFSRESIZE)
 #define DEPS_NTFSLABEL 3
 #define DEPS_NTFSLABEL_MASK (1 << DEPS_NTFSLABEL)
-#define DEPS_NTFSCLUSTER 4
-#define DEPS_NTFSCLUSTER_MASK (1 << DEPS_NTFSCLUSTER)
+#define DEPS_NTFSINFO 4
+#define DEPS_NTFSINFO_MASK (1 << DEPS_NTFSINFO)
 
 #define DEPS_LAST 5
 
@@ -46,7 +47,7 @@ static const UtilDep deps[DEPS_LAST] = {
     {"ntfsfix", NULL, NULL, NULL},
     {"ntfsresize", NULL, NULL, NULL},
     {"ntfslabel", NULL, NULL, NULL},
-    {"ntfscluster", NULL, NULL, NULL},
+    {"ntfsinfo", NULL, NULL, NULL},
 };
 
 static guint32 fs_mode_util[BD_FS_MODE_LAST+1] = {
@@ -55,7 +56,7 @@ static guint32 fs_mode_util[BD_FS_MODE_LAST+1] = {
     DEPS_NTFSFIX_MASK,      /* check */
     DEPS_NTFSFIX_MASK,      /* repair */
     DEPS_NTFSLABEL_MASK,    /* set-label */
-    DEPS_NTFSCLUSTER_MASK,  /* query */
+    DEPS_NTFSINFO_MASK,  /* query */
     DEPS_NTFSRESIZE_MASK,   /* resize */
     DEPS_NTFSLABEL_MASK     /* set-uuid */
 };
@@ -356,7 +357,7 @@ gboolean bd_fs_ntfs_resize (const gchar *device, guint64 new_size, GError **erro
  * Tech category: %BD_FS_TECH_NTFS-%BD_FS_TECH_MODE_QUERY
  */
 BDFSNtfsInfo* bd_fs_ntfs_get_info (const gchar *device, GError **error) {
-    const gchar *args[3] = {"ntfscluster", device, NULL};
+    const gchar *args[4] = {"ntfsinfo", "-m", device, NULL};
     gboolean success = FALSE;
     gchar *output = NULL;
     BDFSNtfsInfo *ret = NULL;
@@ -365,8 +366,9 @@ BDFSNtfsInfo* bd_fs_ntfs_get_info (const gchar *device, GError **error) {
     gchar *val_start = NULL;
     g_autofree gchar* mountpoint = NULL;
     GError *l_error = NULL;
+    size_t cluster_size = 0;
 
-    if (!check_deps (&avail_deps, DEPS_NTFSCLUSTER_MASK, deps, DEPS_LAST, &deps_check_lock, error))
+    if (!check_deps (&avail_deps, DEPS_NTFSINFO_MASK, deps, DEPS_LAST, &deps_check_lock, error))
         return NULL;
 
     mountpoint = bd_fs_get_mountpoint (device, &l_error);
@@ -400,8 +402,9 @@ BDFSNtfsInfo* bd_fs_ntfs_get_info (const gchar *device, GError **error) {
     lines = g_strsplit (output, "\n", 0);
     g_free (output);
     line_p = lines;
+
     /* find the beginning of the (data) section we are interested in */
-    while (line_p && *line_p && !g_str_has_prefix (*line_p, "bytes per volume"))
+    while (line_p && *line_p && !strstr (*line_p, "Cluster Size"))
         line_p++;
     if (!line_p || !(*line_p)) {
         g_set_error (error, BD_FS_ERROR, BD_FS_ERROR_PARSE, "Failed to parse NTFS file system information");
@@ -410,12 +413,12 @@ BDFSNtfsInfo* bd_fs_ntfs_get_info (const gchar *device, GError **error) {
         return NULL;
     }
 
-    /* extract data from something like this: "bytes per volume        : 998240256" */
+    /* extract data from something like this: "Cluster Size: 4096" */
     val_start = strchr (*line_p, ':');
     val_start++;
-    ret->size = g_ascii_strtoull (val_start, NULL, 0);
+    cluster_size = g_ascii_strtoull (val_start, NULL, 0);
 
-    while (line_p && *line_p && !g_str_has_prefix (*line_p, "bytes of free space"))
+    while (line_p && *line_p && !strstr (*line_p, "Volume Size in Clusters"))
         line_p++;
     if (!line_p || !(*line_p)) {
         g_set_error (error, BD_FS_ERROR, BD_FS_ERROR_PARSE, "Failed to parse NTFS file system information");
@@ -424,10 +427,27 @@ BDFSNtfsInfo* bd_fs_ntfs_get_info (const gchar *device, GError **error) {
         return NULL;
     }
 
-    /* extract data from something like this: "bytes of free space     : 992759808" */
+    /* extract data from something like this: "Volume Size in Clusters: 15314943" */
     val_start = strchr (*line_p, ':');
     val_start++;
-    ret->free_space = g_ascii_strtoull (val_start, NULL, 0);
+    ret->size = g_ascii_strtoull (val_start, NULL, 0) * cluster_size;
+
+    while (line_p && *line_p && !strstr (*line_p, "Free Clusters"))
+        line_p++;
+    if (!line_p || !(*line_p)) {
+        g_set_error (error, BD_FS_ERROR, BD_FS_ERROR_PARSE, "Failed to parse NTFS file system information");
+        g_strfreev (lines);
+        bd_fs_ntfs_info_free (ret);
+        return NULL;
+    }
+
+    /* extract data from something like this: "Free Clusters: 7812655 (51,0%)" */
+    val_start = strchr (*line_p, ':');
+    val_start++;
+    ret->free_space = g_ascii_strtoull (val_start, NULL, 0) * cluster_size;
+
+    printf("size: %lu\n", ret->size);
+    printf("free_space: %lu\n", ret->free_space);
 
     g_strfreev (lines);
 
diff --git a/tests/fs_tests/ntfs_test.py b/tests/fs_tests/ntfs_test.py
index c04e39d..ff0fc31 100644
--- a/tests/fs_tests/ntfs_test.py
+++ b/tests/fs_tests/ntfs_test.py
@@ -56,9 +56,9 @@ class NTFSTestAvailability(NTFSNoDevTestCase):
             with self.assertRaisesRegex(GLib.GError, "The 'ntfsfix' utility is not available"):
                 BlockDev.fs_is_tech_avail(BlockDev.FSTech.NTFS, BlockDev.FSTechMode.REPAIR)
 
-        # now try without ntfscluster
-        with utils.fake_path(all_but="ntfscluster"):
-            with self.assertRaisesRegex(GLib.GError, "The 'ntfscluster' utility is not available"):
+        # now try without ntfsinfo
+        with utils.fake_path(all_but="ntfsinfo"):
+            with self.assertRaisesRegex(GLib.GError, "The 'ntfsinfo' utility is not available"):
                 BlockDev.fs_is_tech_avail(BlockDev.FSTech.NTFS, BlockDev.FSTechMode.QUERY)
 
         # now try without ntfsresize
diff --git a/tests/utils.py b/tests/utils.py
index c498c10..ef21507 100644
--- a/tests/utils.py
+++ b/tests/utils.py
@@ -81,7 +81,7 @@ ALL_UTILS = {"lvm", "btrfs", "mkswap", "swaplabel", "multipath", "mpathconf", "d
              "mke2fs", "e2fsck", "tune2fs", "dumpe2fs", "resize2fs",
              "mkfs.f2fs", "fsck.f2fs", "fsck.f2fs", "dump.f2fs", "resize.f2fs",
              "mkfs.nilfs2", "nilfs-tune", "nilfs-resize",
-             "mkntfs", "ntfsfix", "ntfsresize", "ntfslabel", "ntfscluster",
+             "mkntfs", "ntfsfix", "ntfsresize", "ntfslabel", "ntfsinfo",
              "mkfs.vfat", "fatlabel", "fsck.vfat", "vfat-resize",
              "mkfs.xfs", "xfs_db", "xfs_repair", "xfs_admin", "xfs_growfs"}
 

[amurzeau]

Note: this is still a bit slower than using udisks2 2.9.4 which seems to not access the plugged in USB key as much, the maximum udisksctl status time is 0.2s instead of 0.9s.

Also while true; do udisksctl status; done since 2.10 will heavily use disks (their activity led is almost always on) and it will use 400ms instead of 20ms on the same computer (and in both cases with USB key plugged in).

I wanted to highlight this (now smaller) performance regression, I guess 2.9 wasn't refreshing disk usage values explaining why it was faster.

Also, using some applications that monitor disks (like audio application monitoring for new music files) will trigger heavy disk usage for each of these DBus queries:

method call time=1689354488.579350 sender=:1.258 -> destination=org.freedesktop.UDisks2 serial=1940 path=/org/freedesktop/UDisks2; interface=org.freedesktop.DBus.ObjectManager; member=GetManagedObjects
method return time=1689354489.018120 sender=:1.296 -> destination=:1.258 serial=390 reply_serial=1940

foobar2000 under wine trigger the above DBus call every second triggering heavy disk usage even with the above patch.

Apologies for the noise, in fact the patch I made wasn't properly working and always returning 0 for size and free_space, so udisks2 was always calling the function get_size instead of caching the result. (I've fixed the above patch)

There are still disk activity with udisksctl status, because fsck.vfat -nv always return exit code 1, thus the get_info always returns NULL. Maybe that exit code 1 is new in some version of fsck.vfat.
But this prevent caching of the result on udisks2 side.

[vojtechtrefny]

Thank you for the fix, I posted it as a PR #936.

It's really interesting how much difference is there between ntfscluster and ntfsinfo.

[tbzatek]

Thanks for the bugreport, impressive that you managed to analyze the problem down to its root cause.

I still hope these reports will disappear once distributions bump to util-linux-2.39 that should provide ID_FS_LASTBLOCK and ID_FS_BLOCKSIZE udev attributes. Although not sure if ntfs is supported this way but libblkid is definitely the right place for that.