f2fs-tools not working properly since 35.0.2

[salvogiangri]

I'm currently having issues building F2FS system images with the bundled f2fs tools that have been added per my request in #127. Since 35.0.2, make_f2fs/sload_f2fs will report the image size is too small. I'm currently using the same logic as AOSP build_image.py to determine the image size to use. Any suggestions/ways to properly debug the issue? Is this an issue in my end?

[salvogiangri]

Little example here, trying to build odm partition (smallest one):

• As per AOSP build_image.py, image size for dynamic partitions device is calculated as follows:
  • Use du -b -k -s and multiply the result with 1024 to determine the size of the partition occupied in the disk (1709056)
  • Unless specified in the device tree config, add 16MB of reserved size to the previous gathered value (18486272)
  • Round the value so that it is divisible per 4096 (18489344)

This is the output of mkf2fsuserimg.sh with the value calculated above:

in mkf2fsuserimg.sh PATH=/home/salvo/Scrivania/Android/Projects/UN1CA/out/tools/bin:/home/salvo/bin:/usr/local/sbin:/usr/local/bin:/usr/bin:/usr/lib/jvm/default/bin:/usr/bin/site_perl:/usr/bin/vendor_perl:/usr/bin/core_perl:/home/salvo/.local/bin:/home/salvo/.local/bin
truncate -s 18489344 ./out/work_dir/odm/../odm.img
make_f2fs -g android -l odm -O project_quota,extra_attr -O compression,extra_attr -O ro -b 4096 -w 4096 ./out/work_dir/odm/../odm.img

    F2FS-tools: mkfs.f2fs Ver: 1.16.0 (2023-04-11)

Info: Debug level = 1
Info: Label = odm
Info: Trim is enabled
Info: Set conf for android
Info: Enable Project quota
Info: Enable Compression
Info: not exist /proc/version!
Info: Segments per section = 1
Info: Sections per zone = 1
Info: sector size = 512
Info: total sectors = 36112 (17 MB)
Info: zone aligned segment0 blkaddr: 2
        Error: Device size is not sufficient for F2FS volume
        Error: Failed to prepare a super block!!!
        Error: Could not format the device!!!

The image builds correctly if using the minimum value I could find in this specific case, which is 18882560 bytes:

in mkf2fsuserimg.sh PATH=/home/salvo/Scrivania/Android/Projects/UN1CA/out/tools/bin:/home/salvo/bin:/usr/local/sbin:/usr/local/bin:/usr/bin:/usr/lib/jvm/default/bin:/usr/bin/site_perl:/usr/bin/vendor_perl:/usr/bin/core_perl:/home/salvo/.local/bin:/home/salvo/.local/bin
truncate -s 18882560 ./out/work_dir/odm/../odm.img
make_f2fs -g android -l odm -O project_quota,extra_attr -O compression,extra_attr -O ro -b 4096 -w 4096 ./out/work_dir/odm/../odm.img

    F2FS-tools: mkfs.f2fs Ver: 1.16.0 (2023-04-11)

Info: Debug level = 1
Info: Label = odm
Info: Trim is enabled
Info: Set conf for android
Info: Enable Project quota
Info: Enable Compression
Info: open /dev/loop0 failed errno:13 - be careful to overwrite a mounted loopback file.
Info: not exist /proc/version!
Info: Segments per section = 1
Info: Sections per zone = 1
Info: sector size = 512
Info: total sectors = 36880 (18 MB)
Info: zone aligned segment0 blkaddr: 2
Info: format version with
  "6.10.4-arch2-1"
Info: [./out/work_dir/odm/../odm.img] Discarding device
[f2fs_init_sit_area: 640]       Filling sit area at offset 0x00402000
[f2fs_init_nat_area: 674]       Filling nat area at offset 0x00802000
[f2fs_add_default_dentry_root:1257]     Writing default dentry root, at offset 0xc02
[f2fs_write_root_inode:1302]    Writing root inode (hot node), offset 0x1002
[f2fs_update_nat_default:1476]  Writing nat root, at offset 0x00000802
Info: Overprovision ratio = 0.000%
Info: Overprovision segments = 2 (GC reserved = 0)
[f2fs_write_check_point_pack: 855]      Writing main segments, cp at offset 0x00000002
[f2fs_write_check_point_pack: 943]      Writing Segment summary for HOT/WARM/COLD_DATA, at offset 0x00000003
[f2fs_write_check_point_pack: 957]      Writing Segment summary for HOT_NODE, at offset 0x00000004
[f2fs_write_check_point_pack: 969]      Writing Segment summary for WARM_NODE, at offset 0x00000005
[f2fs_write_check_point_pack: 980]      Writing Segment summary for COLD_NODE, at offset 0x00000006
[f2fs_write_check_point_pack: 989]      Writing cp page2, at offset 0x00000007
[f2fs_write_check_point_pack:1008]      Writing NAT bits pages, at offset 0x00000201
[f2fs_write_check_point_pack:1029]      Writing cp page 1 of checkpoint pack 2, at offset 0x00000202
[f2fs_write_check_point_pack:1048]      Writing cp page 2 of checkpoint pack 2, at offset 0x00000207
[f2fs_write_super_block:1082]   Writing super block, at offset 0x00000000
Info: format successful
sload_f2fs -C ./out/work_dir/configs/fs_config-odm -f ./out/work_dir/odm -s ./out/work_dir/configs/file_context-odm -t /odm -T 1640995200 ./out/work_dir/odm/../odm.img
Info: open /dev/loop0 failed errno:13 - be careful to overwrite a mounted loopback file.
Info: not exist /proc/version!
Info: MKFS version
  "6.10.4-arch2-1"
Info: FSCK version
  from "6.10.4-arch2-1"
    to "6.10.4-arch2-1"
Info: superblock features = 6018 :  extra_attr project_quota compression ro
Info: superblock encrypt level = 0, salt = 00000000000000000000000000000000
Info: Segments per section = 1
Info: Sections per zone = 1
Info: total FS sectors = 36880 (18 MB)
Info: CKPT version = 4ffe8759
loaded 16 fs_config entries
Info: flush_journal_entries() n_nats: 1, n_sits: 2
Info: Duplicate valid checkpoint to mirror position 2 -> 514
Info: Write valid nat_bits in checkpoint
Info: write_checkpoint() cur_cp:1
 [ * ] Free segments: 0x1[FIX] (move_one_curseg_info:3143)  --> Move curseg[0] 0 -> 0 after c02

[FIX] (move_one_curseg_info:3143)  --> Move curseg[3] 2 -> 2 after 1202

Info: Write valid nat_bits in checkpoint
Info: write_checkpoint() cur_cp:1
Info: MKFS version
  "6.10.4-arch2-1"
Info: FSCK version
  from "6.10.4-arch2-1"
    to "6.10.4-arch2-1"
Info: superblock features = 6018 :  extra_attr project_quota compression ro
Info: superblock encrypt level = 0, salt = 00000000000000000000000000000000
Info: Segments per section = 1
Info: Sections per zone = 1
Info: total FS sectors = 36880 (18 MB)
Info: CKPT version = 4ffe8759
Info: version timestamp cur: 0, prev: 0
[update_superblock: 884] Info: Done to update superblock
Info: Checked valid nat_bits in checkpoint
Info: checkpoint state = 181 :  trimmed nat_bits unmount

[FSCK] Max image size: 16 MB, Free space: 2 MB
[FSCK] Unreachable nat entries                        [Ok..] [0x0]
[FSCK] SIT valid block bitmap checking                [Ok..]
[FSCK] Hard link checking for regular file            [Ok..] [0x0]
[FSCK] valid_block_count matching with CP             [Ok..] [0x1b3]
[FSCK] valid_node_count matching with CP (de lookup)  [Ok..] [0xf]
[FSCK] valid_node_count matching with CP (nat lookup) [Ok..] [0xf]
[FSCK] valid_inode_count matched with CP              [Ok..] [0xe]
[FSCK] free segment_count matched with CP             [Ok..] [0x1]
[FSCK] next block offset is free                      [Ok..]
[FSCK] fixing SIT types
[FSCK] other corrupted bugs                           [Ok..]

Done: 0.110765 secs
truncate -s 23068672 ./out/work_dir/odm/../odm.img
make_f2fs -g android -l odm -O project_quota,extra_attr -O compression,extra_attr -O ro -b 4096 -w 4096 ./out/work_dir/odm/../odm.img

    F2FS-tools: mkfs.f2fs Ver: 1.16.0 (2023-04-11)

Info: Debug level = 1
Info: Label = odm
Info: Trim is enabled
Info: Set conf for android
Info: Enable Project quota
Info: Enable Compression
Info: open /dev/loop0 failed errno:13 - be careful to overwrite a mounted loopback file.
Info: not exist /proc/version!
Info: Segments per section = 1
Info: Sections per zone = 1
Info: sector size = 512
Info: total sectors = 45056 (22 MB)
Info: zone aligned segment0 blkaddr: 2
Info: format version with
  "6.10.4-arch2-1"
Info: [./out/work_dir/odm/../odm.img] Discarding device
[f2fs_init_sit_area: 640]       Filling sit area at offset 0x00402000
[f2fs_init_nat_area: 674]       Filling nat area at offset 0x00802000
[f2fs_add_default_dentry_root:1257]     Writing default dentry root, at offset 0xc02
[f2fs_write_root_inode:1302]    Writing root inode (hot node), offset 0x1202
[f2fs_update_nat_default:1476]  Writing nat root, at offset 0x00000802
Info: Overprovision ratio = 0.000%
Info: Overprovision segments = 2 (GC reserved = 0)
[f2fs_write_check_point_pack: 855]      Writing main segments, cp at offset 0x00000002
[f2fs_write_check_point_pack: 943]      Writing Segment summary for HOT/WARM/COLD_DATA, at offset 0x00000003
[f2fs_write_check_point_pack: 957]      Writing Segment summary for HOT_NODE, at offset 0x00000004
[f2fs_write_check_point_pack: 969]      Writing Segment summary for WARM_NODE, at offset 0x00000005
[f2fs_write_check_point_pack: 980]      Writing Segment summary for COLD_NODE, at offset 0x00000006
[f2fs_write_check_point_pack: 989]      Writing cp page2, at offset 0x00000007
[f2fs_write_check_point_pack:1008]      Writing NAT bits pages, at offset 0x00000201
[f2fs_write_check_point_pack:1029]      Writing cp page 1 of checkpoint pack 2, at offset 0x00000202
[f2fs_write_check_point_pack:1048]      Writing cp page 2 of checkpoint pack 2, at offset 0x00000207
[f2fs_write_super_block:1082]   Writing super block, at offset 0x00000000
Info: format successful
sload_f2fs -C ./out/work_dir/configs/fs_config-odm -f ./out/work_dir/odm -s ./out/work_dir/configs/file_context-odm -t /odm -T 1640995200 ./out/work_dir/odm/../odm.img
Info: open /dev/loop0 failed errno:13 - be careful to overwrite a mounted loopback file.
Info: not exist /proc/version!
Info: MKFS version
  "6.10.4-arch2-1"
Info: FSCK version
  from "6.10.4-arch2-1"
    to "6.10.4-arch2-1"
Info: superblock features = 6018 :  extra_attr project_quota compression ro
Info: superblock encrypt level = 0, salt = 00000000000000000000000000000000
Info: Segments per section = 1
Info: Sections per zone = 1
Info: total FS sectors = 45056 (22 MB)
Info: CKPT version = 4ffe8759
loaded 16 fs_config entries
Info: flush_journal_entries() n_nats: 1, n_sits: 2
Info: Duplicate valid checkpoint to mirror position 2 -> 514
Info: Write valid nat_bits in checkpoint
Info: write_checkpoint() cur_cp:1
 [ * ] Free segments: 0x2[FIX] (move_one_curseg_info:3143)  --> Move curseg[0] 0 -> 0 after c02

[FIX] (move_one_curseg_info:3143)  --> Move curseg[3] 3 -> 3 after 1402

Info: Write valid nat_bits in checkpoint
Info: write_checkpoint() cur_cp:1
Info: MKFS version
  "6.10.4-arch2-1"
Info: FSCK version
  from "6.10.4-arch2-1"
    to "6.10.4-arch2-1"
Info: superblock features = 6018 :  extra_attr project_quota compression ro
Info: superblock encrypt level = 0, salt = 00000000000000000000000000000000
Info: Segments per section = 1
Info: Sections per zone = 1
Info: total FS sectors = 45056 (22 MB)
Info: CKPT version = 4ffe8759
Info: version timestamp cur: 0, prev: 0
[update_superblock: 884] Info: Done to update superblock
Info: Checked valid nat_bits in checkpoint
Info: checkpoint state = 181 :  trimmed nat_bits unmount

[FSCK] Max image size: 16 MB, Free space: 4 MB
[FSCK] Unreachable nat entries                        [Ok..] [0x0]
[FSCK] SIT valid block bitmap checking                [Ok..]
[FSCK] Hard link checking for regular file            [Ok..] [0x0]
[FSCK] valid_block_count matching with CP             [Ok..] [0x1b3]
[FSCK] valid_node_count matching with CP (de lookup)  [Ok..] [0xf]
[FSCK] valid_node_count matching with CP (nat lookup) [Ok..] [0xf]
[FSCK] valid_inode_count matched with CP              [Ok..] [0xe]
[FSCK] free segment_count matched with CP             [Ok..] [0x2]
[FSCK] next block offset is free                      [Ok..]
[FSCK] fixing SIT types
[FSCK] other corrupted bugs                           [Ok..]

Done: 0.104722 secs

[anatol]

The latest released version is 35.0.2 https://developer.android.com/tools/releases/platform-tools

Do you mean 34.0.5? Could you please build the head of the project (which is 35.0.2) and see if the error still exist? If yes - could you please post the debug logs as you did earlier?

[salvogiangri]

The latest released version is 35.0.2 https://developer.android.com/tools/releases/platform-tools

Do you mean 34.0.5? Could you please build the head of the project (which is 35.0.2) and see if the error still exist? If yes - could you please post the debug logs as you did earlier?

My bad, it’s 35.0.2. I’m already building from upstream branch (7cb4b93), will share more info later.

[salvogiangri]

This was tested with binaries built from the upstream branch (7cb4b93). Binaries have been built with the following set of cmds:

mkdir -p "build" && cd "build"
cmake \
    -DCMAKE_SYSTEM_NAME="Linux" \
    -DCMAKE_SYSTEM_PROCESSOR="x86_64" \
    -DCMAKE_BUILD_TYPE="Release" \
    -DCMAKE_C_COMPILER_LAUNCHER="ccache" \
    -DCMAKE_CXX_COMPILER_LAUNCHER="ccache" \
    -DCMAKE_C_COMPILER="clang" \
    -DCMAKE_CXX_COMPILER="clang++" \
    -DANDROID_TOOLS_USE_BUNDLED_FMT=ON \
    -DANDROID_TOOLS_USE_BUNDLED_LIBUSB=ON \
    ..
make -j16

mkf2fsuserimg command:

mkf2fsuserimg "odm.img" "18489344" \
    -C "configs/fs_config-odm" -f "odm" -s "configs/file_context-odm" \
    -t "odm" -T 1640995200 -L "odm" \
    --prjquota --compression --readonly \
    --sldc 0 -b 4096

As pointed out in #158 (comment), the image will only build when giving as size "18882560" (vs. the actual 18489344 calculated before), but strangely enough the output image is bigger, 23068672 bytes.

Here's fsck.f2fs output:

❯ fsck.f2fs -l odm.img
magic:                         4076150800
major_ver:                     1
Filesystem volume name:        odm
minor_ver:                     16
log_sectorsize:                9
log_sectors_per_block:         3
log_blocksize:                 12
log_blocks_per_seg:            9
segs_per_sec:                  1
secs_per_zone:                 1
checksum_offset:               0
block_count:                   5632
section_count:                 4
segment_count:                 10
segment_count_ckpt:            2
segment_count_sit:             2
segment_count_nat:             2
segment_count_ssa:             0
segment_count_main:            4
segment0_blkaddr:              2
cp_blkaddr:                    2
sit_blkaddr:                   1026
nat_blkaddr:                   2050
ssa_blkaddr:                   3074
main_blkaddr:                  3074
root_ino:                      3
node_ino:                      1
meta_ino:                      2
cp_payload:                    0
crc:                           0
version                       6.10.4-arch2-1
checkpoint_ver:                1731694337
user_block_count:              1024
valid_block_count:             435
rsvd_segment_count:            0
overprov_segment_count:        2
free_segment_count:            2
alloc_type[CURSEG_HOT_NODE]:   1
alloc_type[CURSEG_WARM_NODE]:  0
alloc_type[CURSEG_COLD_NODE]:  0
cur_node_segno[0]:             3
cur_node_segno[1]:             0
cur_node_segno[2]:             0
cur_node_blkoff[0]:            497
cur_node_blkoff[1]:            0
cur_node_blkoff[2]:            0
alloc_type[CURSEG_HOT_DATA]:   1
alloc_type[CURSEG_WARM_DATA]:  0
alloc_type[CURSEG_COLD_DATA]:  0
cur_data_segno[0]:             0
cur_data_segno[1]:             0
cur_data_segno[2]:             0
cur_data_blkoff[0]:            286
cur_data_blkoff[1]:            0
cur_data_blkoff[2]:            0
ckpt_flags:                    385
cp_pack_total_block_count:     8
cp_pack_start_sum:             1
valid_node_count:              15
valid_inode_count:             14
next_free_nid:                 4
sit_ver_bitmap_bytesize:       64
nat_ver_bitmap_bytesize:       64
checksum_offset:               4092
elapsed_time:                  0
sit_nat_version_bitmap[0]:     0

[salvogiangri]

Another thing to note, I completely missed this: aosp-mirror/platform_build@158a5eb
Basically, the 10% of the disk usage value is added together with the reserved_size value (which again is 16MB unless specified via BOARD_*IMAGE_PARTITION_RESERVED_SIZE flag in the device tree) when calculating the image size. This however still didn't solve the issue as the final calculated image size is now 18657280, still lower than required (18882560). Is this an actual issue with the tool or is just some f2fs shenanigans?

[salvogiangri]

Bumping this as I found the root cause of this issue being commit 5da4e524, reverting it fixes this issue.