Time comparison of searching for a block group

The best way to look up a block group item is to exactly specify the
item in the min and max search key and also set the nr_items to 1.

However, what happens if we do it less optimally, like:
- not specifying the offset (length), but searching between 0 and
  ULONG_MAX
- not setting nr_items = 1, but higher

First test:

    # ./btrfs-fi-df-simple.py /path
    Data, single: total=1.92TiB, used=1.59TiB
    System, single: total=32.00MiB, used=352.00KiB
    Metadata, single: total=30.00GiB, used=25.10GiB
    GlobalReserve, single: total=512.00MiB, used=0.00B

    # ./block_group_search_timing.py /path
    No block group vaddr given, loading chunk tree and selecting a random one.
        0.072216 sec choosing block group at 2168950095872

    min (2168950095872 BLOCK_GROUP_ITEM 1073741824)
    max (2168950095872 BLOCK_GROUP_ITEM 1073741824)
    nr_items 1
        0.000437 sec result (2168950095872 BLOCK_GROUP_ITEM 1073741824)
        0.000073 sec done

    min (2168950095872 BLOCK_GROUP_ITEM 0)
    max (2168950095872 BLOCK_GROUP_ITEM 18446744073709551615)
    nr_items 1
        0.000422 sec result (2168950095872 BLOCK_GROUP_ITEM 1073741824)
        0.000065 sec done

    min (2168950095872 BLOCK_GROUP_ITEM 0)
    max (2168950095872 BLOCK_GROUP_ITEM 18446744073709551615)
    nr_items 4096
        0.000458 sec result (2168950095872 BLOCK_GROUP_ITEM 1073741824)
        0.000076 sec done

    min (2168950095872 BLOCK_GROUP_ITEM 1073741824)
    max (2168950095872 BLOCK_GROUP_ITEM 1073741824)
    nr_items 4294967295
        0.000443 sec result (2168950095872 BLOCK_GROUP_ITEM 1073741824)
        0.000052 sec done

    min (2168950095872 BLOCK_GROUP_ITEM 0)
    max (2168950095872 BLOCK_GROUP_ITEM 18446744073709551615)
    nr_items 4294967295
        0.000417 sec result (2168950095872 BLOCK_GROUP_ITEM 1073741824)
        0.000089 sec done

This looks pretty good. The values are small enough to not even know if
I'm measuring python itself or the ioctl.

Now, let's try this on a huge filesystem:

    # ./btrfs-fi-df-simple.py /path
    Data, single: total=33.07TiB, used=24.86TiB
    System, DUP: total=8.00MiB, used=4.67MiB
    System, single: total=4.00MiB, used=0.00B
    Metadata, DUP: total=365.00GiB, used=356.58GiB
    Metadata, single: total=8.00MiB, used=0.00B
    GlobalReserve, single: total=512.00MiB, used=70.05MiB

    # ./block_group_search_timing.py /path
    No block group vaddr given, loading chunk tree and selecting a random one.
        1.103642 sec choosing block group at 22418148032512

    min (22418148032512 BLOCK_GROUP_ITEM 1073741824)
    max (22418148032512 BLOCK_GROUP_ITEM 1073741824)
    nr_items 1
        0.003747 sec result (22418148032512 BLOCK_GROUP_ITEM 1073741824)
        0.000100 sec done

    min (22418148032512 BLOCK_GROUP_ITEM 0)
    max (22418148032512 BLOCK_GROUP_ITEM 18446744073709551615)
    nr_items 1
        0.000401 sec result (22418148032512 BLOCK_GROUP_ITEM 1073741824)
        0.000074 sec done

    min (22418148032512 BLOCK_GROUP_ITEM 0)
    max (22418148032512 BLOCK_GROUP_ITEM 18446744073709551615)
    nr_items 4096
        1190.294175 sec result (22418148032512 BLOCK_GROUP_ITEM 1073741824)
        5.774579 sec done

    min (22418148032512 BLOCK_GROUP_ITEM 1073741824)
    max (22418148032512 BLOCK_GROUP_ITEM 1073741824)
    nr_items 4294967295
        0.151328 sec result (22418148032512 BLOCK_GROUP_ITEM 1073741824)
        0.000292 sec done

    min (22418148032512 BLOCK_GROUP_ITEM 0)
    max (22418148032512 BLOCK_GROUP_ITEM 18446744073709551615)
    nr_items 4294967295
        4.707032 sec result (22418148032512 BLOCK_GROUP_ITEM 1073741824)
        4.795762 sec done

Almost 1200 seconds are spent doing random disk read I/O. During this
test, the filesystem was already used quite heavily by other processes.
The last search makes use of the data that is now in disk cache.  When
executing this again, the earlier search is now also using about 4
seconds:

    min (22418148032512 BLOCK_GROUP_ITEM 0)
    max (22418148032512 BLOCK_GROUP_ITEM 18446744073709551615)
    nr_items 4096
        4.634718 sec result (22418148032512 BLOCK_GROUP_ITEM 1073741824)
        4.674435 sec done

    min (22418148032512 BLOCK_GROUP_ITEM 0)
    max (22418148032512 BLOCK_GROUP_ITEM 18446744073709551615)
    nr_items 4294967295
        4.845431 sec result (22418148032512 BLOCK_GROUP_ITEM 1073741824)
        4.652890 sec done

examples/block_group_search_timing.py

@@ -0,0 +1,52 @@
+#!/usr/bin/python
+
+from __future__ import print_function
+from btrfs.ctree import (
+    ULLONG_MAX, ULONG_MAX,
+    Key,
+    EXTENT_TREE_OBJECTID, BLOCK_GROUP_ITEM_KEY
+)
+import btrfs
+import random
+import sys
+import time
+
+
+fs = btrfs.FileSystem(sys.argv[1])
+if len(sys.argv) > 2:
+    vaddr = int(sys.argv[2])
+    chunks = list(fs.chunks(vaddr, vaddr, 1))
+    if len(chunks) != 1:
+        print("no chunk at vaddr {0}".format(vaddr))
+        sys.exit(1)
+    chunk = chunks[0]
+else:
+    print("No block group vaddr given, loading chunk tree and selecting a random one.")
+    start = time.time()
+    chunks = list(fs.chunks())
+    now = time.time()
+    chunk = chunks[random.randint(0, len(chunks)-1)]
+    print("    {0:.6f} sec choosing block group at {1}".format(now-start, chunk.vaddr))
+
+
+def time_bg_search(vaddr, length, nr_items):
+    tree = EXTENT_TREE_OBJECTID
+    min_offset = length if length is not None else 0
+    max_offset = length if length is not None else ULLONG_MAX
+    min_key = Key(vaddr, BLOCK_GROUP_ITEM_KEY, min_offset)
+    max_key = Key(vaddr, BLOCK_GROUP_ITEM_KEY, max_offset)
+    print("\nmin {0}\nmax {1}\nnr_items {2}".format(min_key, max_key, nr_items))
+    start = time.time()
+    for header, data in btrfs.ioctl.search(fs.fd, tree, min_key, max_key, nr_items=nr_items):
+        bg = btrfs.ctree.BlockGroup(header, data)
+        now = time.time()
+        print("    {0:.6f} sec result {1}".format(now-start, bg.key))
+        start = now
+    now = time.time()
+    print("    {0:.6f} sec done".format(now-start))
+
+time_bg_search(chunk.vaddr, chunk.length, 1)
+time_bg_search(chunk.vaddr, None, 1)
+time_bg_search(chunk.vaddr, None, 4096)
+time_bg_search(chunk.vaddr, chunk.length, ULONG_MAX)
+time_bg_search(chunk.vaddr, None, ULONG_MAX)