containers / fuse-overlayfs

FUSE implementation for overlayfs
GNU General Public License v2.0
502 stars 83 forks source link

wrong inode on entries read by readdir instead of readdirplus #391

Open amurzeau opened 1 year ago

amurzeau commented 1 year ago

Hi,

Description

In some cases, fuse-overlayfs will report the inode number from the lowest layer instead of the upper layer.

In the test case below:

This confuses code that uses the inode number to detect hardlinks.

I've discovered this while executing buildkitd's TestDiffLazyBlobMerge test with fuse-overlayfs snapshotter.

I guess this issue is too specific and won't be fixed, but this can serve as documentation about it.


Test case

#!/bin/sh

set -e

# Create test.go

cat > test.go << EOF
package main

import (
    "fmt"
    "os"
    "syscall"
)

func readdir(dirname string) error {
    f, err := os.Open(dirname)
    if err != nil {
        return err
    }
    f.Readdirnames(-1)
    f.Close()

    return nil
}

func stat(path string) {
    st, err := os.Lstat(path)
    if err != nil {
        fmt.Printf("failed to stat %v: %v\n", path, err)
        os.Exit(1)
    }
    fmt.Printf("%v inode: %v\n", path, st.Sys().(*syscall.Stat_t).Ino)
}

func main() {
    // readdirnames will do getdents64 sycalls without any other syscalls inbetween (no stat)
    err := readdir("bin")
    if err != nil {
        fmt.Printf("failed to readdir bin: %v\n", err)
        os.Exit(1)
    }

    stat("bin/arch")
    stat("bin/busybox")
}
EOF

mkdir -p lower1/bin lower2/bin merged
(cd lower1/bin; touch $(seq 1 50))
dd if=/dev/urandom of=lower2/bin/busybox count=1 2> /dev/null
ln lower2/bin/busybox lower2/bin/arch
dd if=/dev/urandom of=lower1/bin/busybox count=1 2> /dev/null
ln -s busybox lower1/bin/arch

ls -lai lower1/bin/busybox lower1/bin/arch lower2/bin/busybox lower2/bin/arch

fuse-overlayfs -o lowerdir=$PWD/lower1:$PWD/lower2 merged

(cd merged; go run ../test.go)

(command -v fusermount > /dev/null && fusermount -u merged) ||
(command -v fusermount3 > /dev/null && fusermount3 -u merged)

Output:

# ./test.sh
8007522 lrwxrwxrwx    1 root     root             7 Mar 31 15:35 lower1/bin/arch -> busybox
8007521 -rw-r--r--    1 root     root           512 Mar 31 15:35 lower1/bin/busybox
8007520 -rw-r--r--    2 root     root           512 Mar 31 15:35 lower2/bin/arch
8007520 -rw-r--r--    2 root     root           512 Mar 31 15:35 lower2/bin/busybox
bin/arch inode: 8007520
bin/busybox inode: 8007520
8007520 lrwxrwxrwx    1 root     root             7 Mar 31 15:35 merged/bin/arch -> busybox
8007520 -rw-r--r--    1 root     root           512 Mar 31 15:35 merged/bin/busybox

Expected output:

# ./test.sh
8007522 lrwxrwxrwx    1 root     root             7 Mar 31 15:35 lower1/bin/arch -> busybox
8007521 -rw-r--r--    1 root     root           512 Mar 31 15:35 lower1/bin/busybox
8007520 -rw-r--r--    2 root     root           512 Mar 31 15:35 lower2/bin/arch
8007520 -rw-r--r--    2 root     root           512 Mar 31 15:35 lower2/bin/busybox
bin/arch inode: 8007522
bin/busybox inode: 8007521
8007522 lrwxrwxrwx    1 root     root             7 Mar 31 15:35 merged/bin/arch -> busybox
8007521 -rw-r--r--    1 root     root           512 Mar 31 15:35 merged/bin/busybox

I've tried to debug it a bit, and found that the issue comes from this:

fuse-overlayfs in debug will print this:

uid=unchanged
gid=unchanged
upperdir=NOT USED
workdir=NOT USED
lowerdir=/tmp/test/test2/lower1:/tmp/test/test2/lower2
mountpoint=merged
plugins=<none>
fsync=enabled
FUSE library version: 3.12.0
unique: 2, opcode: INIT (26), nodeid: 0, insize: 104, pid: 0
INIT: 7.37
flags=0x73fffffb
max_readahead=0x00020000
   INIT: 7.31
   flags=0x4051f069
   max_readahead=0x00020000
   max_write=0x00100000
   max_background=0
   congestion_threshold=0
   time_gran=1
   unique: 2, success, outsize: 80
unique: 4, opcode: GETATTR (3), nodeid: 1, insize: 56, pid: 29273
ovl_getattr(ino=1)
   unique: 4, success, outsize: 120
unique: 6, opcode: LOOKUP (1), nodeid: 1, insize: 48, pid: 29273
ovl_lookup(parent=1, name=go.work)
   unique: 6, success, outsize: 144
unique: 8, opcode: LOOKUP (1), nodeid: 1, insize: 47, pid: 29273
ovl_lookup(parent=1, name=go.mod)
   unique: 8, success, outsize: 144
unique: 10, opcode: LOOKUP (1), nodeid: 1, insize: 44, pid: 29328
ovl_lookup(parent=1, name=bin)
   unique: 10, success, outsize: 144
unique: 12, opcode: OPENDIR (27), nodeid: 93967843290160, insize: 48, pid: 29328
ovl_opendir(ino=93967843290160)
   unique: 12, success, outsize: 32
unique: 14, opcode: READDIRPLUS (44), nodeid: 93967843290160, insize: 80, pid: 29328
ovl_readdirplus(ino=93967843290160, size=4096, offset=0)
   unique: 14, success, outsize: 4016
unique: 16, opcode: READDIR (28), nodeid: 93967843290160, insize: 80, pid: 29328
ovl_readdir(ino=93967843290160, size=4096, offset=31)
   unique: 16, success, outsize: 944
unique: 18, opcode: READDIR (28), nodeid: 93967843290160, insize: 80, pid: 29328
ovl_readdir(ino=93967843290160, size=4096, offset=66)
   unique: 18, success, outsize: 16
unique: 20, opcode: RELEASEDIR (29), nodeid: 93967843290160, insize: 64, pid: 0
ovl_releasedir(ino=93967843290160)
   unique: 20, success, outsize: 16
unique: 22, opcode: LOOKUP (1), nodeid: 93967843290160, insize: 45, pid: 29328
ovl_lookup(parent=93967843290160, name=arch)
   unique: 22, success, outsize: 144
bin/arch inode: 8007520
unique: 24, opcode: LOOKUP (1), nodeid: 93967843290160, insize: 48, pid: 29328
ovl_lookup(parent=93967843290160, name=busybox)
   unique: 24, success, outsize: 144
bin/busybox inode: 8007520
unique: 26, opcode: READLINK (5), nodeid: 139747124619552, insize: 40, pid: 29332
ovl_readlink(ino=139747124619552)
   unique: 26, success, outsize: 23
unique: 28, opcode: READLINK (5), nodeid: 139747124619552, insize: 40, pid: 29332
ovl_readlink(ino=139747124619552)
   unique: 28, success, outsize: 23

I've added debug logs to find this. Using the code from https://github.com/amurzeau/fuse-overlayfs/tree/debug-bad-inodes, here is the result (fuse-overlayfs is run in debug mode to get its output):

# ./test.sh
8007522 lrwxrwxrwx    1 root     root             7 Mar 31 15:48 lower1/bin/arch -> busybox
8007521 -rw-r--r--    1 root     root           512 Mar 31 15:48 lower1/bin/busybox
8007520 -rw-r--r--    2 root     root           512 Mar 31 15:48 lower2/bin/arch
8007520 -rw-r--r--    2 root     root           512 Mar 31 15:48 lower2/bin/busybox
unknown argument ignored: lazytime
uid=unchanged
gid=unchanged
upperdir=NOT USED
workdir=NOT USED
lowerdir=/tmp/test/test2/lower1:/tmp/test/test2/lower2
mountpoint=merged
plugins=<none>
fsync=enabled
load_dir 1703: n=0
make_ovl_node: . node_lookups = 0 (init)
load_dir 1715: n=0x7f2acf8b5f70
load_dir 1722: n->parent: 0 parent_whiteout_path=.wh.
load_dir 1730: it: 0x7f2acf8b5a50
load_dir 1738: file_exists .wh.: ret: -1, errno: 2
load_dir 1746: statat .: ret: 0, errno: 2
load_dir 1761: opendir ., ret: 0, errno: 2
load_dir 1786: readdir .: .., ino: 8007473
load_dir 1786: readdir .: bin, ino: 8007465
load_dir 1807: hash_lookup bin: child: NULL
load_dir 1816: file_exists ./.wh.bin: ret: -1, errno: 2
load_dir 1843: get_whiteout_name bin wh: 0
make_ovl_node: ./bin node_lookups = 0 (init)
load_dir 1883: make_ovl_node bin child: 0x7f2acf9508c0
load_dir 1894: insert_node n: 0x7f2acf8b5f70 child: 0x7f2acf9508c0
load_dir 1786: readdir .: ., ino: 8007464
load_dir 1776: readdir ., ret: -1, errno: 0
load_dir 1904: is_directory_opaque .: ret 0 errno: 2
load_dir 1730: it: 0x7f2acf8b5a50
load_dir 1733: last layer
load_dir 1738: file_exists .wh.: ret: -1, errno: 2
load_dir 1746: statat .: ret: 0, errno: 2
load_dir 1761: opendir ., ret: 0, errno: 2
load_dir 1786: readdir .: .., ino: 8007473
load_dir 1786: readdir .: bin, ino: 8007467
load_dir 1796: hash_lookup bin: child: 0x7f2acf9508c0, whiteout: 0, upper_layer: 0
load_dir 1786: readdir .: ., ino: 8007466
load_dir 1776: readdir ., ret: 0, errno: 0
load_dir 1904: is_directory_opaque .: ret 0 errno: 2
load_dir 1919: get_timeout > 0
main: root->ino->lookups = 2
FUSE library version: 3.12.0
unique: 2, opcode: INIT (26), nodeid: 0, insize: 104, pid: 0
INIT: 7.37
flags=0x73fffffb
max_readahead=0x00020000
   INIT: 7.31
   flags=0x4051f069
   max_readahead=0x00020000
   max_write=0x00100000
   max_background=0
   congestion_threshold=0
   time_gran=1
   unique: 2, success, outsize: 80
unique: 4, opcode: GETATTR (3), nodeid: 1, insize: 56, pid: 28558
ovl_getattr(ino=1)
do_lookup_file 2091: parent: 1, name: (null)
   unique: 4, success, outsize: 120
unique: 6, opcode: LOOKUP (1), nodeid: 1, insize: 48, pid: 28558
ovl_lookup(parent=1, name=go.work)
do_lookup_file 2091: parent: 1, name: go.work
do_lookup_file 2115: node: 0, pnode: 0x7f2acf8b5f70, pnode->loaded: 1
do_lookup_file 2246: returning node 0 with inode 0
   unique: 6, success, outsize: 144
unique: 8, opcode: LOOKUP (1), nodeid: 1, insize: 47, pid: 28558
ovl_lookup(parent=1, name=go.mod)
do_lookup_file 2091: parent: 1, name: go.mod
do_lookup_file 2115: node: 0, pnode: 0x7f2acf8b5f70, pnode->loaded: 1
do_lookup_file 2246: returning node 0 with inode 0
   unique: 8, success, outsize: 144
unique: 10, opcode: LOOKUP (1), nodeid: 1, insize: 44, pid: 28613
ovl_lookup(parent=1, name=bin)
do_lookup_file 2091: parent: 1, name: bin
do_lookup_file 2115: node: 0x7f2acf9508c0, pnode: 0x7f2acf8b5f70, pnode->loaded: 1
do_lookup_file 2246: returning node 0x7f2acf9508c0 with inode 8007465
ovl_lookup: bin: node: 0x7f2acf9508c0, inode=8007465
load_dir 1703: n=0x7f2acf9508c0
load_dir 1715: n=0x7f2acf9508c0
load_dir 1722: n->parent: 0x7f2acf8b5f70 parent_whiteout_path=./.wh.bin
load_dir 1730: it: 0x7f2acf8b5a50
load_dir 1738: file_exists ./.wh.bin: ret: -1, errno: 2
load_dir 1746: statat bin: ret: 0, errno: 2
load_dir 1761: opendir bin, ret: 0, errno: 2
load_dir 1786: readdir bin: 13, ino: 8007482
load_dir 1807: hash_lookup 13: child: NULL
load_dir 1816: file_exists bin/.wh.13: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 13 wh: 0
make_ovl_node: bin/13 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 13 child: 0x7f2acf9509c0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf9509c0
load_dir 1786: readdir bin: 45, ino: 8007514
load_dir 1807: hash_lookup 45: child: NULL
load_dir 1816: file_exists bin/.wh.45: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 45 wh: 0
make_ovl_node: bin/45 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 45 child: 0x7f2acf950a40
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf950a40
load_dir 1786: readdir bin: 40, ino: 8007509
load_dir 1807: hash_lookup 40: child: NULL
load_dir 1816: file_exists bin/.wh.40: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 40 wh: 0
make_ovl_node: bin/40 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 40 child: 0x7f2acf950ac0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf950ac0
load_dir 1786: readdir bin: 19, ino: 8007488
load_dir 1807: hash_lookup 19: child: NULL
load_dir 1816: file_exists bin/.wh.19: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 19 wh: 0
make_ovl_node: bin/19 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 19 child: 0x7f2acf950b40
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf950b40
load_dir 1786: readdir bin: 35, ino: 8007504
load_dir 1807: hash_lookup 35: child: NULL
load_dir 1816: file_exists bin/.wh.35: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 35 wh: 0
make_ovl_node: bin/35 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 35 child: 0x7f2acf950bc0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf950bc0
load_dir 1786: readdir bin: 44, ino: 8007513
load_dir 1807: hash_lookup 44: child: NULL
load_dir 1816: file_exists bin/.wh.44: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 44 wh: 0
make_ovl_node: bin/44 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 44 child: 0x7f2acf8b5190
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf8b5190
load_dir 1786: readdir bin: 21, ino: 8007490
load_dir 1807: hash_lookup 21: child: NULL
load_dir 1816: file_exists bin/.wh.21: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 21 wh: 0
make_ovl_node: bin/21 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 21 child: 0x7f2acf8b5210
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf8b5210
load_dir 1786: readdir bin: .., ino: 8007464
load_dir 1786: readdir bin: 47, ino: 8007516
load_dir 1807: hash_lookup 47: child: NULL
load_dir 1816: file_exists bin/.wh.47: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 47 wh: 0
make_ovl_node: bin/47 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 47 child: 0x7f2acf8b5290
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf8b5290
load_dir 1786: readdir bin: 23, ino: 8007492
load_dir 1807: hash_lookup 23: child: NULL
load_dir 1816: file_exists bin/.wh.23: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 23 wh: 0
make_ovl_node: bin/23 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 23 child: 0x7f2acf8b5310
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf8b5310
load_dir 1786: readdir bin: 24, ino: 8007493
load_dir 1807: hash_lookup 24: child: NULL
load_dir 1816: file_exists bin/.wh.24: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 24 wh: 0
make_ovl_node: bin/24 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 24 child: 0x7f2acf8b5390
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf8b5390
load_dir 1786: readdir bin: 14, ino: 8007483
load_dir 1807: hash_lookup 14: child: NULL
load_dir 1816: file_exists bin/.wh.14: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 14 wh: 0
make_ovl_node: bin/14 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 14 child: 0x7f2acf8b5410
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf8b5410
load_dir 1786: readdir bin: 39, ino: 8007508
load_dir 1807: hash_lookup 39: child: NULL
load_dir 1816: file_exists bin/.wh.39: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 39 wh: 0
make_ovl_node: bin/39 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 39 child: 0x7f2acf8b5490
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf8b5490
load_dir 1786: readdir bin: 22, ino: 8007491
load_dir 1807: hash_lookup 22: child: NULL
load_dir 1816: file_exists bin/.wh.22: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 22 wh: 0
make_ovl_node: bin/22 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 22 child: 0x55b32a8c6330
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x55b32a8c6330
load_dir 1786: readdir bin: 30, ino: 8007499
load_dir 1807: hash_lookup 30: child: NULL
load_dir 1816: file_exists bin/.wh.30: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 30 wh: 0
make_ovl_node: bin/30 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 30 child: 0x55b32a8c63b0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x55b32a8c63b0
load_dir 1786: readdir bin: 3, ino: 8007471
load_dir 1807: hash_lookup 3: child: NULL
load_dir 1816: file_exists bin/.wh.3: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 3 wh: 0
make_ovl_node: bin/3 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 3 child: 0x55b32a8c6430
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x55b32a8c6430
load_dir 1786: readdir bin: 49, ino: 8007518
load_dir 1807: hash_lookup 49: child: NULL
load_dir 1816: file_exists bin/.wh.49: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 49 wh: 0
make_ovl_node: bin/49 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 49 child: 0x55b32a8c64b0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x55b32a8c64b0
load_dir 1786: readdir bin: 34, ino: 8007503
load_dir 1807: hash_lookup 34: child: NULL
load_dir 1816: file_exists bin/.wh.34: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 34 wh: 0
make_ovl_node: bin/34 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 34 child: 0x55b32a8c6530
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x55b32a8c6530
load_dir 1786: readdir bin: 2, ino: 8007470
load_dir 1807: hash_lookup 2: child: NULL
load_dir 1816: file_exists bin/.wh.2: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 2 wh: 0
make_ovl_node: bin/2 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 2 child: 0x55b32a8c65b0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x55b32a8c65b0
load_dir 1786: readdir bin: 43, ino: 8007512
load_dir 1807: hash_lookup 43: child: NULL
load_dir 1816: file_exists bin/.wh.43: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 43 wh: 0
make_ovl_node: bin/43 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 43 child: 0x55b32a8c6630
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x55b32a8c6630
load_dir 1786: readdir bin: 9, ino: 8007478
load_dir 1807: hash_lookup 9: child: NULL
load_dir 1816: file_exists bin/.wh.9: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 9 wh: 0
make_ovl_node: bin/9 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 9 child: 0x55b32a8c6720
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x55b32a8c6720
load_dir 1786: readdir bin: busybox, ino: 8007521
load_dir 1807: hash_lookup busybox: child: NULL
load_dir 1816: file_exists bin/.wh.busybox: ret: -1, errno: 2
load_dir 1843: get_whiteout_name busybox wh: 0
make_ovl_node: bin/busybox node_lookups = 0 (init)
load_dir 1883: make_ovl_node busybox child: 0x55b32a8c67a0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x55b32a8c67a0
load_dir 1786: readdir bin: 27, ino: 8007496
load_dir 1807: hash_lookup 27: child: NULL
load_dir 1816: file_exists bin/.wh.27: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 27 wh: 0
make_ovl_node: bin/27 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 27 child: 0x55b32a8c6820
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x55b32a8c6820
load_dir 1786: readdir bin: 1, ino: 8007469
load_dir 1807: hash_lookup 1: child: NULL
load_dir 1816: file_exists bin/.wh.1: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 1 wh: 0
make_ovl_node: bin/1 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 1 child: 0x55b32a8c68a0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x55b32a8c68a0
load_dir 1786: readdir bin: 41, ino: 8007510
load_dir 1807: hash_lookup 41: child: NULL
load_dir 1816: file_exists bin/.wh.41: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 41 wh: 0
make_ovl_node: bin/41 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 41 child: 0x55b32a8c6920
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x55b32a8c6920
load_dir 1786: readdir bin: 33, ino: 8007502
load_dir 1807: hash_lookup 33: child: NULL
load_dir 1816: file_exists bin/.wh.33: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 33 wh: 0
make_ovl_node: bin/33 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 33 child: 0x55b32a8c69a0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x55b32a8c69a0
load_dir 1786: readdir bin: 4, ino: 8007472
load_dir 1807: hash_lookup 4: child: NULL
load_dir 1816: file_exists bin/.wh.4: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 4 wh: 0
make_ovl_node: bin/4 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 4 child: 0x55b32a8c6a20
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x55b32a8c6a20
load_dir 1786: readdir bin: 20, ino: 8007489
load_dir 1807: hash_lookup 20: child: NULL
load_dir 1816: file_exists bin/.wh.20: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 20 wh: 0
make_ovl_node: bin/20 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 20 child: 0x7f2acf76d030
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76d030
load_dir 1786: readdir bin: 29, ino: 8007498
load_dir 1807: hash_lookup 29: child: NULL
load_dir 1816: file_exists bin/.wh.29: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 29 wh: 0
make_ovl_node: bin/29 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 29 child: 0x7f2acf76d0b0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76d0b0
load_dir 1786: readdir bin: 32, ino: 8007501
load_dir 1807: hash_lookup 32: child: NULL
load_dir 1816: file_exists bin/.wh.32: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 32 wh: 0
make_ovl_node: bin/32 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 32 child: 0x7f2acf76d130
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76d130
load_dir 1786: readdir bin: 15, ino: 8007484
load_dir 1807: hash_lookup 15: child: NULL
load_dir 1816: file_exists bin/.wh.15: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 15 wh: 0
make_ovl_node: bin/15 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 15 child: 0x7f2acf76d1b0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76d1b0
load_dir 1786: readdir bin: 38, ino: 8007507
load_dir 1807: hash_lookup 38: child: NULL
load_dir 1816: file_exists bin/.wh.38: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 38 wh: 0
make_ovl_node: bin/38 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 38 child: 0x7f2acf76d230
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76d230
load_dir 1786: readdir bin: 16, ino: 8007485
load_dir 1807: hash_lookup 16: child: NULL
load_dir 1816: file_exists bin/.wh.16: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 16 wh: 0
make_ovl_node: bin/16 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 16 child: 0x7f2acf76d2b0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76d2b0
load_dir 1786: readdir bin: 7, ino: 8007476
load_dir 1807: hash_lookup 7: child: NULL
load_dir 1816: file_exists bin/.wh.7: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 7 wh: 0
make_ovl_node: bin/7 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 7 child: 0x7f2acf76d330
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76d330
load_dir 1786: readdir bin: 37, ino: 8007506
load_dir 1807: hash_lookup 37: child: NULL
load_dir 1816: file_exists bin/.wh.37: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 37 wh: 0
make_ovl_node: bin/37 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 37 child: 0x7f2acf76d820
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76d820
load_dir 1786: readdir bin: 8, ino: 8007477
load_dir 1807: hash_lookup 8: child: NULL
load_dir 1816: file_exists bin/.wh.8: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 8 wh: 0
make_ovl_node: bin/8 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 8 child: 0x7f2acf76d8a0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76d8a0
load_dir 1786: readdir bin: 5, ino: 8007474
load_dir 1807: hash_lookup 5: child: NULL
load_dir 1816: file_exists bin/.wh.5: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 5 wh: 0
make_ovl_node: bin/5 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 5 child: 0x7f2acf76d920
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76d920
load_dir 1786: readdir bin: 6, ino: 8007475
load_dir 1807: hash_lookup 6: child: NULL
load_dir 1816: file_exists bin/.wh.6: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 6 wh: 0
make_ovl_node: bin/6 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 6 child: 0x7f2acf76d9a0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76d9a0
load_dir 1786: readdir bin: 50, ino: 8007519
load_dir 1807: hash_lookup 50: child: NULL
load_dir 1816: file_exists bin/.wh.50: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 50 wh: 0
make_ovl_node: bin/50 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 50 child: 0x7f2acf76da20
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76da20
load_dir 1786: readdir bin: 17, ino: 8007486
load_dir 1807: hash_lookup 17: child: NULL
load_dir 1816: file_exists bin/.wh.17: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 17 wh: 0
make_ovl_node: bin/17 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 17 child: 0x7f2acf76daa0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76daa0
load_dir 1786: readdir bin: arch, ino: 8007522
load_dir 1807: hash_lookup arch: child: NULL
load_dir 1816: file_exists bin/.wh.arch: ret: -1, errno: 2
load_dir 1843: get_whiteout_name arch wh: 0
make_ovl_node: bin/arch node_lookups = 0 (init)
load_dir 1883: make_ovl_node arch child: 0x7f2acf76db20
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76db20
load_dir 1786: readdir bin: 18, ino: 8007487
load_dir 1807: hash_lookup 18: child: NULL
load_dir 1816: file_exists bin/.wh.18: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 18 wh: 0
make_ovl_node: bin/18 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 18 child: 0x7f2acf76c030
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76c030
load_dir 1786: readdir bin: 42, ino: 8007511
load_dir 1807: hash_lookup 42: child: NULL
load_dir 1816: file_exists bin/.wh.42: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 42 wh: 0
make_ovl_node: bin/42 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 42 child: 0x7f2acf76c0b0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76c0b0
load_dir 1786: readdir bin: 12, ino: 8007481
load_dir 1807: hash_lookup 12: child: NULL
load_dir 1816: file_exists bin/.wh.12: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 12 wh: 0
make_ovl_node: bin/12 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 12 child: 0x7f2acf76c130
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76c130
load_dir 1786: readdir bin: 46, ino: 8007515
load_dir 1807: hash_lookup 46: child: NULL
load_dir 1816: file_exists bin/.wh.46: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 46 wh: 0
make_ovl_node: bin/46 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 46 child: 0x7f2acf76c1b0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76c1b0
load_dir 1786: readdir bin: 26, ino: 8007495
load_dir 1807: hash_lookup 26: child: NULL
load_dir 1816: file_exists bin/.wh.26: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 26 wh: 0
make_ovl_node: bin/26 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 26 child: 0x7f2acf76c230
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76c230
load_dir 1786: readdir bin: 36, ino: 8007505
load_dir 1807: hash_lookup 36: child: NULL
load_dir 1816: file_exists bin/.wh.36: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 36 wh: 0
make_ovl_node: bin/36 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 36 child: 0x7f2acf76c2b0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76c2b0
load_dir 1786: readdir bin: ., ino: 8007465
load_dir 1786: readdir bin: 10, ino: 8007479
load_dir 1807: hash_lookup 10: child: NULL
load_dir 1816: file_exists bin/.wh.10: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 10 wh: 0
make_ovl_node: bin/10 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 10 child: 0x7f2acf76c330
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76c330
load_dir 1786: readdir bin: 11, ino: 8007480
load_dir 1807: hash_lookup 11: child: NULL
load_dir 1816: file_exists bin/.wh.11: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 11 wh: 0
make_ovl_node: bin/11 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 11 child: 0x7f2acf76c420
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76c420
load_dir 1786: readdir bin: 48, ino: 8007517
load_dir 1807: hash_lookup 48: child: NULL
load_dir 1816: file_exists bin/.wh.48: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 48 wh: 0
make_ovl_node: bin/48 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 48 child: 0x7f2acf76c4a0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76c4a0
load_dir 1786: readdir bin: 31, ino: 8007500
load_dir 1807: hash_lookup 31: child: NULL
load_dir 1816: file_exists bin/.wh.31: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 31 wh: 0
make_ovl_node: bin/31 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 31 child: 0x7f2acf76c520
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76c520
load_dir 1786: readdir bin: 28, ino: 8007497
load_dir 1807: hash_lookup 28: child: NULL
load_dir 1816: file_exists bin/.wh.28: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 28 wh: 0
make_ovl_node: bin/28 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 28 child: 0x7f2acf76c5a0
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76c5a0
load_dir 1786: readdir bin: 25, ino: 8007494
load_dir 1807: hash_lookup 25: child: NULL
load_dir 1816: file_exists bin/.wh.25: ret: -1, errno: 2
load_dir 1843: get_whiteout_name 25 wh: 0
make_ovl_node: bin/25 node_lookups = 0 (init)
load_dir 1883: make_ovl_node 25 child: 0x7f2acf76c620
load_dir 1894: insert_node n: 0x7f2acf9508c0 child: 0x7f2acf76c620
load_dir 1776: readdir bin, ret: -1, errno: 0
load_dir 1904: is_directory_opaque bin: ret 0 errno: 2
load_dir 1730: it: 0x7f2acf8b5a50
load_dir 1733: last layer
load_dir 1738: file_exists ./.wh.bin: ret: -1, errno: 2
load_dir 1746: statat bin: ret: 0, errno: 2
load_dir 1761: opendir bin, ret: 0, errno: 2
load_dir 1786: readdir bin: .., ino: 8007466
load_dir 1786: readdir bin: busybox, ino: 8007520
load_dir 1796: hash_lookup busybox: child: 0x55b32a8c67a0, whiteout: 0, upper_layer: 0
load_dir 1786: readdir bin: arch, ino: 8007520
load_dir 1796: hash_lookup arch: child: 0x7f2acf76db20, whiteout: 0, upper_layer: 0
load_dir 1786: readdir bin: ., ino: 8007467
load_dir 1776: readdir bin, ret: 0, errno: 0
load_dir 1904: is_directory_opaque bin: ret 0 errno: 2
load_dir 1919: get_timeout > 0
ovl_lookup: bin: reload_dir: node: 0x7f2acf9508c0, inode=8007465
ovl_lookup: bin: rpl_stat: node: 0x7f2acf9508c0, err: 0, e.attr.ino: 8007465
ovl_lookup: bin: node_to_inode: ino: 94228001352688
ovl_lookup: bin: node->ino->lookups++: 1
   unique: 10, success, outsize: 144
unique: 12, opcode: OPENDIR (27), nodeid: 94228001352688, insize: 48, pid: 28613
ovl_opendir(ino=94228001352688)
do_lookup_file 2091: parent: 94228001352688, name: (null)
   unique: 12, success, outsize: 32
unique: 14, opcode: READDIRPLUS (44), nodeid: 94228001352688, insize: 80, pid: 28613
ovl_readdirplus(ino=94228001352688, size=4096, offset=0)
reload_tbl: 40 node_lookups++ = 1
reload_tbl: 40: node->ino->lookups++: 1
reload_tbl: 41 node_lookups++ = 1
reload_tbl: 41: node->ino->lookups++: 1
reload_tbl: 42 node_lookups++ = 1
reload_tbl: 42: node->ino->lookups++: 1
reload_tbl: 43 node_lookups++ = 1
reload_tbl: 43: node->ino->lookups++: 1
reload_tbl: 44 node_lookups++ = 1
reload_tbl: 44: node->ino->lookups++: 1
reload_tbl: 45 node_lookups++ = 1
reload_tbl: 45: node->ino->lookups++: 1
reload_tbl: 46 node_lookups++ = 1
reload_tbl: 46: node->ino->lookups++: 1
reload_tbl: 47 node_lookups++ = 1
reload_tbl: 47: node->ino->lookups++: 1
reload_tbl: 48 node_lookups++ = 1
reload_tbl: 48: node->ino->lookups++: 1
reload_tbl: 49 node_lookups++ = 1
reload_tbl: 49: node->ino->lookups++: 1
reload_tbl: 1 node_lookups++ = 1
reload_tbl: 1: node->ino->lookups++: 1
reload_tbl: 2 node_lookups++ = 1
reload_tbl: 2: node->ino->lookups++: 1
reload_tbl: 3 node_lookups++ = 1
reload_tbl: 3: node->ino->lookups++: 1
reload_tbl: 4 node_lookups++ = 1
reload_tbl: 4: node->ino->lookups++: 1
reload_tbl: 5 node_lookups++ = 1
reload_tbl: 5: node->ino->lookups++: 1
reload_tbl: 6 node_lookups++ = 1
reload_tbl: 6: node->ino->lookups++: 1
reload_tbl: 7 node_lookups++ = 1
reload_tbl: 7: node->ino->lookups++: 1
reload_tbl: 30 node_lookups++ = 1
reload_tbl: 30: node->ino->lookups++: 1
reload_tbl: 8 node_lookups++ = 1
reload_tbl: 8: node->ino->lookups++: 1
reload_tbl: 9 node_lookups++ = 1
reload_tbl: 9: node->ino->lookups++: 1
reload_tbl: 31 node_lookups++ = 1
reload_tbl: 31: node->ino->lookups++: 1
reload_tbl: 32 node_lookups++ = 1
reload_tbl: 32: node->ino->lookups++: 1
reload_tbl: 33 node_lookups++ = 1
reload_tbl: 33: node->ino->lookups++: 1
reload_tbl: 34 node_lookups++ = 1
reload_tbl: 34: node->ino->lookups++: 1
reload_tbl: 35 node_lookups++ = 1
reload_tbl: 35: node->ino->lookups++: 1
reload_tbl: 36 node_lookups++ = 1
reload_tbl: 36: node->ino->lookups++: 1
reload_tbl: 37 node_lookups++ = 1
reload_tbl: 37: node->ino->lookups++: 1
reload_tbl: 38 node_lookups++ = 1
reload_tbl: 38: node->ino->lookups++: 1
reload_tbl: 39 node_lookups++ = 1
reload_tbl: 39: node->ino->lookups++: 1
reload_tbl: 20 node_lookups++ = 1
reload_tbl: 20: node->ino->lookups++: 1
reload_tbl: arch node_lookups++ = 1
reload_tbl: arch: node->ino->lookups++: 1
reload_tbl: 21 node_lookups++ = 1
reload_tbl: 21: node->ino->lookups++: 1
reload_tbl: 22 node_lookups++ = 1
reload_tbl: 22: node->ino->lookups++: 1
reload_tbl: 23 node_lookups++ = 1
reload_tbl: 23: node->ino->lookups++: 1
reload_tbl: 24 node_lookups++ = 1
reload_tbl: 24: node->ino->lookups++: 1
reload_tbl: 25 node_lookups++ = 1
reload_tbl: 25: node->ino->lookups++: 1
reload_tbl: 26 node_lookups++ = 1
reload_tbl: 26: node->ino->lookups++: 1
reload_tbl: 27 node_lookups++ = 1
reload_tbl: 27: node->ino->lookups++: 1
reload_tbl: 28 node_lookups++ = 1
reload_tbl: 28: node->ino->lookups++: 1
reload_tbl: 29 node_lookups++ = 1
reload_tbl: 29: node->ino->lookups++: 1
reload_tbl: 10 node_lookups++ = 1
reload_tbl: 10: node->ino->lookups++: 1
reload_tbl: 11 node_lookups++ = 1
reload_tbl: 11: node->ino->lookups++: 1
reload_tbl: 12 node_lookups++ = 1
reload_tbl: 12: node->ino->lookups++: 1
reload_tbl: 13 node_lookups++ = 1
reload_tbl: 13: node->ino->lookups++: 1
reload_tbl: 14 node_lookups++ = 1
reload_tbl: 14: node->ino->lookups++: 1
reload_tbl: 15 node_lookups++ = 1
reload_tbl: 15: node->ino->lookups++: 1
reload_tbl: 16 node_lookups++ = 1
reload_tbl: 16: node->ino->lookups++: 1
reload_tbl: 17 node_lookups++ = 1
reload_tbl: 17: node->ino->lookups++: 1
reload_tbl: 18 node_lookups++ = 1
reload_tbl: 18: node->ino->lookups++: 1
reload_tbl: 19 node_lookups++ = 1
reload_tbl: 19: node->ino->lookups++: 1
reload_tbl: 50 node_lookups++ = 1
reload_tbl: 50: node->ino->lookups++: 1
reload_tbl: busybox node_lookups++ = 1
reload_tbl: busybox: node->ino->lookups++: 1
reload_tbl: 40: offset >= 2, node->ino->lookups++: 2
reload_tbl: 41: offset >= 2, node->ino->lookups++: 2
reload_tbl: 42: offset >= 2, node->ino->lookups++: 2
reload_tbl: 43: offset >= 2, node->ino->lookups++: 2
reload_tbl: 44: offset >= 2, node->ino->lookups++: 2
reload_tbl: 45: offset >= 2, node->ino->lookups++: 2
reload_tbl: 46: offset >= 2, node->ino->lookups++: 2
reload_tbl: 47: offset >= 2, node->ino->lookups++: 2
reload_tbl: 48: offset >= 2, node->ino->lookups++: 2
reload_tbl: 49: offset >= 2, node->ino->lookups++: 2
reload_tbl: 1: offset >= 2, node->ino->lookups++: 2
reload_tbl: 2: offset >= 2, node->ino->lookups++: 2
reload_tbl: 3: offset >= 2, node->ino->lookups++: 2
reload_tbl: 4: offset >= 2, node->ino->lookups++: 2
reload_tbl: 5: offset >= 2, node->ino->lookups++: 2
reload_tbl: 6: offset >= 2, node->ino->lookups++: 2
reload_tbl: 7: offset >= 2, node->ino->lookups++: 2
reload_tbl: 30: offset >= 2, node->ino->lookups++: 2
reload_tbl: 8: offset >= 2, node->ino->lookups++: 2
reload_tbl: 9: offset >= 2, node->ino->lookups++: 2
reload_tbl: 31: offset >= 2, node->ino->lookups++: 2
reload_tbl: 32: offset >= 2, node->ino->lookups++: 2
reload_tbl: 33: offset >= 2, node->ino->lookups++: 2
   unique: 14, success, outsize: 4016
unique: 16, opcode: READDIR (28), nodeid: 94228001352688, insize: 80, pid: 28613
ovl_readdir(ino=94228001352688, size=4096, offset=31)
   unique: 16, success, outsize: 944
unique: 18, opcode: READDIR (28), nodeid: 94228001352688, insize: 80, pid: 28613
ovl_readdir(ino=94228001352688, size=4096, offset=66)
   unique: 18, success, outsize: 16
unique: 20, opcode: RELEASEDIR (29), nodeid: 94228001352688, insize: 64, pid: 0
ovl_releasedir(ino=94228001352688)
ovl_releasedir: 40 node_lookups-- = 0, ino: 0x55b32a8c6b30, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 41 node_lookups-- = 0, ino: 0x7f2acf8b5870, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 42 node_lookups-- = 0, ino: 0x7f2acf76dcb0, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 43 node_lookups-- = 0, ino: 0x7f2acf8b5780, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 44 node_lookups-- = 0, ino: 0x55b32a8c6c20, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 45 node_lookups-- = 0, ino: 0x55b32a8c6ce0, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 46 node_lookups-- = 0, ino: 0x7f2acf76dd10, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 47 node_lookups-- = 0, ino: 0x55b32a8c6c80, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 48 node_lookups-- = 0, ino: 0x7f2acf76c830, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 49 node_lookups-- = 0, ino: 0x7f2acf950810, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 1 node_lookups-- = 0, ino: 0x7f2acf8b5840, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 2 node_lookups-- = 0, ino: 0x7f2acf950870, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 3 node_lookups-- = 0, ino: 0x7f2acf9507e0, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 4 node_lookups-- = 0, ino: 0x7f2acf8b58d0, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 5 node_lookups-- = 0, ino: 0x7f2acf76d770, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 6 node_lookups-- = 0, ino: 0x7f2acf76d7a0, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 7 node_lookups-- = 0, ino: 0x7f2acf76d6e0, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 30 node_lookups-- = 0, ino: 0x7f2acf9507b0, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 8 node_lookups-- = 0, ino: 0x7f2acf76d740, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 9 node_lookups-- = 0, ino: 0x7f2acf8b57b0, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 31 node_lookups-- = 0, ino: 0x7f2acf76c860, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 32 node_lookups-- = 0, ino: 0x7f2acf76d620, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 33 node_lookups-- = 0, ino: 0x7f2acf8b58a0, &dummy_ino: 0x55b32a8c62c0
ovl_releasedir: 34 node_lookups-- = 0, ino: 0x7f2acf950840, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x55b32a8c6530 (34)
node_free: n: 0x55b32a8c6530, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 35 node_lookups-- = 0, ino: 0x55b32a8c6b90, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf950bc0 (35)
node_free: n: 0x7f2acf950bc0, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 36 node_lookups-- = 0, ino: 0x7f2acf76dd70, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf76c2b0 (36)
node_free: n: 0x7f2acf76c2b0, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 37 node_lookups-- = 0, ino: 0x7f2acf76d710, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf76d820 (37)
node_free: n: 0x7f2acf76d820, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 38 node_lookups-- = 0, ino: 0x7f2acf76d680, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf76d230 (38)
node_free: n: 0x7f2acf76d230, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 39 node_lookups-- = 0, ino: 0x7f2acf950750, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf8b5490 (39)
node_free: n: 0x7f2acf8b5490, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 20 node_lookups-- = 0, ino: 0x7f2acf8b5900, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf76d030 (20)
node_free: n: 0x7f2acf76d030, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: arch node_lookups-- = 0, ino: 0x7f2acf76dc50, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf76db20 (arch)
node_free: n: 0x7f2acf76db20, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 21 node_lookups-- = 0, ino: 0x55b32a8c6c50, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf8b5210 (21)
node_free: n: 0x7f2acf8b5210, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 22 node_lookups-- = 0, ino: 0x7f2acf950780, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x55b32a8c6330 (22)
node_free: n: 0x55b32a8c6330, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 23 node_lookups-- = 0, ino: 0x7f2acf9506c0, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf8b5310 (23)
node_free: n: 0x7f2acf8b5310, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 24 node_lookups-- = 0, ino: 0x7f2acf9506f0, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf8b5390 (24)
node_free: n: 0x7f2acf8b5390, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 25 node_lookups-- = 0, ino: 0x7f2acf76c8c0, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf76c620 (25)
node_free: n: 0x7f2acf76c620, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 26 node_lookups-- = 0, ino: 0x7f2acf76dd40, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf76c230 (26)
node_free: n: 0x7f2acf76c230, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 27 node_lookups-- = 0, ino: 0x7f2acf8b5810, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x55b32a8c6820 (27)
node_free: n: 0x55b32a8c6820, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 28 node_lookups-- = 0, ino: 0x7f2acf76c890, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf76c5a0 (28)
node_free: n: 0x7f2acf76c5a0, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 29 node_lookups-- = 0, ino: 0x7f2acf8b5930, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf76d0b0 (29)
node_free: n: 0x7f2acf76d0b0, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 10 node_lookups-- = 0, ino: 0x7f2acf76dda0, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf76c330 (10)
node_free: n: 0x7f2acf76c330, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 11 node_lookups-- = 0, ino: 0x7f2acf76ddd0, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf76c420 (11)
node_free: n: 0x7f2acf76c420, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 12 node_lookups-- = 0, ino: 0x7f2acf76dce0, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf76c130 (12)
node_free: n: 0x7f2acf76c130, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 13 node_lookups-- = 0, ino: 0x55b32a8c6cb0, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf9509c0 (13)
node_free: n: 0x7f2acf9509c0, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 14 node_lookups-- = 0, ino: 0x7f2acf950720, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf8b5410 (14)
node_free: n: 0x7f2acf8b5410, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 15 node_lookups-- = 0, ino: 0x7f2acf76d650, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf76d1b0 (15)
node_free: n: 0x7f2acf76d1b0, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 16 node_lookups-- = 0, ino: 0x7f2acf76d6b0, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf76d2b0 (16)
node_free: n: 0x7f2acf76d2b0, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 17 node_lookups-- = 0, ino: 0x7f2acf76dc20, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf76daa0 (17)
node_free: n: 0x7f2acf76daa0, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 18 node_lookups-- = 0, ino: 0x7f2acf76dc80, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf76c030 (18)
node_free: n: 0x7f2acf76c030, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 19 node_lookups-- = 0, ino: 0x55b32a8c6b60, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf950b40 (19)
node_free: n: 0x7f2acf950b40, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: 50 node_lookups-- = 0, ino: 0x7f2acf76d7d0, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x7f2acf76da20 (50)
node_free: n: 0x7f2acf76da20, n->parent: 0x7f2acf9508c0, loaded = 0
ovl_releasedir: busybox node_lookups-- = 0, ino: 0x7f2acf8b57e0, &dummy_ino: 0x55b32a8c62c0
do_forget: i->lookups <= 0: 0
hash_delete: pnode: 0x7f2acf9508c0 (bin), node: 0x55b32a8c67a0 (busybox)
node_free: n: 0x55b32a8c67a0, n->parent: 0x7f2acf9508c0, loaded = 0
do_lookup_file 2091: parent: 94228001352688, name: (null)
   unique: 20, success, outsize: 16
unique: 22, opcode: LOOKUP (1), nodeid: 94228001352688, insize: 45, pid: 28613
ovl_lookup(parent=94228001352688, name=arch)
do_lookup_file 2091: parent: 94228001352688, name: arch
do_lookup_file 2115: node: 0, pnode: 0x7f2acf9508c0, pnode->loaded: 0
do_lookup_file 2123: node == NULL && !pnode->loaded
do_lookup_file 2136: statat on bin/arch, node: 0
do_lookup_file 2190: checking if whiteout2 exists bin/.wh.arch
do_lookup_file 2192: check file_exists2: ret: -1, errno: 2
do_lookup_file 2203: whiteout2 does not exists, wh_name = (null)
make_ovl_node: bin/arch node_lookups = 0 (init)
do_lookup_file 2208: node = 0x7f2acf76c6a0, inode: 8007522
do_lookup_file 2236: insert node
do_lookup_file 2136: statat on bin/arch, node: 0x7f2acf76c6a0
do_lookup_file 2182: setting node->tmp_ino to 8007520
do_lookup_file 2246: returning node 0x7f2acf76c6a0 with inode 8007520
ovl_lookup: arch: node: 0x7f2acf76c6a0, inode=8007520
ovl_lookup: arch: rpl_stat: node: 0x7f2acf76c6a0, err: 0, e.attr.ino: 8007520
ovl_lookup: arch: node_to_inode: ino: 139821846022432
ovl_lookup: arch: node->ino->lookups++: 1
   unique: 22, success, outsize: 144
bin/arch inode: 8007520
unique: 24, opcode: LOOKUP (1), nodeid: 94228001352688, insize: 48, pid: 28613
ovl_lookup(parent=94228001352688, name=busybox)
do_lookup_file 2091: parent: 94228001352688, name: busybox
do_lookup_file 2115: node: 0, pnode: 0x7f2acf9508c0, pnode->loaded: 0
do_lookup_file 2123: node == NULL && !pnode->loaded
do_lookup_file 2136: statat on bin/busybox, node: 0
do_lookup_file 2190: checking if whiteout2 exists bin/.wh.busybox
do_lookup_file 2192: check file_exists2: ret: -1, errno: 2
do_lookup_file 2203: whiteout2 does not exists, wh_name = (null)
make_ovl_node: bin/busybox node_lookups = 0 (init)
do_lookup_file 2208: node = 0x7f2acf76c720, inode: 8007521
do_lookup_file 2236: insert node
do_lookup_file 2136: statat on bin/busybox, node: 0x7f2acf76c720
do_lookup_file 2182: setting node->tmp_ino to 8007520
do_lookup_file 2246: returning node 0x7f2acf76c720 with inode 8007520
ovl_lookup: busybox: node: 0x7f2acf76c720, inode=8007520
ovl_lookup: busybox: rpl_stat: node: 0x7f2acf76c720, err: 0, e.attr.ino: 8007520
ovl_lookup: busybox: node_to_inode: ino: 139821846022480
ovl_lookup: busybox: node->ino->lookups++: 1
   unique: 24, success, outsize: 144
bin/busybox inode: 8007520
unique: 26, opcode: READLINK (5), nodeid: 139821846022432, insize: 40, pid: 28617
ovl_readlink(ino=139821846022432)
do_lookup_file 2091: parent: 139821846022432, name: (null)
   unique: 26, success, outsize: 23
unique: 28, opcode: READLINK (5), nodeid: 139821846022432, insize: 40, pid: 28617
ovl_readlink(ino=139821846022432)
do_lookup_file 2091: parent: 139821846022432, name: (null)
   unique: 28, success, outsize: 23
8007520 lrwxrwxrwx    1 root     root             7 Mar 31 15:48 merged/bin/arch -> busybox
8007520 -rw-r--r--    1 root     root           512 Mar 31 15:48 merged/bin/busybox
node_mark_all_free: : n->ino->lookups = 0
node_mark_all_free: bin: n->ino->lookups = 0
node_mark_all_free: 40: n->ino->lookups = 0
node_mark_all_free: 41: n->ino->lookups = 0
node_mark_all_free: 42: n->ino->lookups = 0
node_mark_all_free: 43: n->ino->lookups = 0
node_mark_all_free: 44: n->ino->lookups = 0
node_mark_all_free: 45: n->ino->lookups = 0
node_mark_all_free: 46: n->ino->lookups = 0
node_mark_all_free: 47: n->ino->lookups = 0
node_mark_all_free: 48: n->ino->lookups = 0
node_mark_all_free: 49: n->ino->lookups = 0
node_mark_all_free: 1: n->ino->lookups = 0
node_mark_all_free: 2: n->ino->lookups = 0
node_mark_all_free: 3: n->ino->lookups = 0
node_mark_all_free: 4: n->ino->lookups = 0
node_mark_all_free: 5: n->ino->lookups = 0
node_mark_all_free: 6: n->ino->lookups = 0
node_mark_all_free: 7: n->ino->lookups = 0
node_mark_all_free: 30: n->ino->lookups = 0
node_mark_all_free: 8: n->ino->lookups = 0
node_mark_all_free: 9: n->ino->lookups = 0
node_mark_all_free: 31: n->ino->lookups = 0
node_mark_all_free: 32: n->ino->lookups = 0
node_mark_all_free: 33: n->ino->lookups = 0
node_mark_all_free: arch: n->ino->lookups = 0
node_mark_all_free: busybox: n->ino->lookups = 0