• Jakob Unterwurzacher's avatar
    tests: make TestTypeChange robust against outside interference · da5ff9a7
    Jakob Unterwurzacher authored
    I have suddenly seen TestTypeChange hang forever, waiting for the
    FORGET that never arrives. The first concern was that the assumption
    that the FORGET always follows the delete was wrong. Checking the
    kernel source code, the FORGET should really, actually always follow
    the delete.
    
    Looking more closely on the debug trace showed this:
    
            LOOKUP i1 [".Trash-1026"] 12b
                 OK, {i1234 g0 tE=0s tA=0s {M0100644 SZ=0 L=0 0:0 B0*4096 i0:1234 A 0.000000 M 0.000000 C 0.000000}}
    
    This is the desktop environment looking for the trash folder.
    And because the test is stupid, it returned the same dummy
    inode i1234. This means the kernel had one extra reference
    to this inode and, of course, did not send a FORGET when
    "file" was deleted.
    
    I made testTypeChangeIno only react to expected file names
    now, and added a log output should we wait more than ~5
    seconds for the FORGET. The log message then repeats indefinitely
    every 5 seconds.
    
            ~/go/src/github.com/hanwen/go-fuse/fs$ go test -v -run TestTypeChange
            === RUN   TestTypeChange
            20:50:18.491584 rx 2: INIT i0 {7.31 Ra 0x20000 CACHE_SYMLINKS,POSIX_LOCKS,SPLICE_MOVE,SPLICE_READ,READDIRPLUS,READDIRPLUS_AUTO,PARALLEL_DIROPS,ABORT_ERROR,EXPLICIT_INVAL_DATA,ASYNC_READ,EXPORT_SUPPORT,DONT_MASK,NO_OPENDIR_SUPPORT,SPLICE_WRITE,FLOCK_LOCKS,AUTO_INVAL_DATA,HANDLE_KILLPRIV,MAX_PAGES,POSIX_ACL,ATOMIC_O_TRUNC,BIG_WRITES,IOCTL_DIR,ASYNC_DIO,WRITEBACK_CACHE,NO_OPEN_SUPPORT}
            20:50:18.491728 tx 2:     OK, {7.28 Ra 0x20000 NO_OPEN_SUPPORT,BIG_WRITES,PARALLEL_DIROPS,READDIRPLUS,ASYNC_READ,AUTO_INVAL_DATA 0/0 Wr 0x10000 Tg 0x0}
            20:50:18.491857 rx 4: ACCESS i1 {u=1026 g=1026 r}
            20:50:18.491873 tx 4:     OK
            20:50:18.492028 rx 6: LOOKUP i1 [".go-fuse-epoll-hack"] 20b
            20:50:18.492110 tx 6:     2=no such file or directory, {i0 g0 tE=0s tA=0s {M00 SZ=0 L=0 0:0 B0*0 i0:0 A 0.000000 M 0.000000 C 0.000000}}
            20:50:18.492147 rx 8: CREATE i1 {0100100 [TRUNC,WRONLY,CREAT,0x8000] (00)} [".go-fuse-epoll-hack"] 20b
            20:50:18.492207 tx 8:     OK, {i18446744073709551615 g0 {M0100644 SZ=0 L=1 0:0 B0*0 i0:18446744073709551615 A 0.000000 M 0.000000 C 0.000000} &{18446744073709551615 0 0}}
            20:50:18.492291 rx 10: LOOKUP i1 [".Trash"] 7b
            20:50:18.492340 tx 10:     OK, {i1234 g0 tE=0s tA=0s {M0100644 SZ=0 L=0 0:0 B0*4096 i0:1234 A 0.000000 M 0.000000 C 0.000000}}
            20:50:18.492354 rx 12: POLL i18446744073709551615
            20:50:18.492359 tx 12:     38=function not implemented
            20:50:18.492370 rx 14: LOOKUP i1 [".go-fuse-epoll-hack"] 20b
            20:50:18.492378 tx 14:     2=no such file or directory, {i0 g0 tE=0s tA=0s {M00 SZ=0 L=0 0:0 B0*0 i0:0 A 0.000000 M 0.000000 C 0.000000}}
            20:50:18.492389 rx 16: GETATTR i1234 {Fh 0}
            20:50:18.492398 tx 16:     OK, {tA=0s {M0100644 SZ=0 L=0 0:0 B0*4096 i0:1234 A 0.000000 M 0.000000 C 0.000000}}
            20:50:18.492412 rx 18: FLUSH i18446744073709551615 {Fh 18446744073709551615}
            20:50:18.492417 tx 18:     5=input/output error
            20:50:18.492427 rx 20: LOOKUP i1 [".go-fuse-epoll-hack"] 20b
            20:50:18.492435 tx 20:     2=no such file or directory, {i0 g0 tE=0s tA=0s {M00 SZ=0 L=0 0:0 B0*0 i0:0 A 0.000000 M 0.000000 C 0.000000}}
            20:50:18.492450 rx 22: RELEASE i18446744073709551615 {Fh 18446744073709551615 WRONLY,0x8000  L0}
            20:50:18.492456 tx 22:     5=input/output error
            20:50:18.492469 rx 24: LOOKUP i1 ["file"] 5b
            20:50:18.492477 tx 24:     OK, {i1234 g0 tE=0s tA=0s {M0100644 SZ=0 L=0 0:0 B0*4096 i0:1234 A 0.000000 M 0.000000 C 0.000000}}
            20:50:18.492489 rx 26: LOOKUP i1 [".Trash-1026"] 12b
            20:50:18.492497 tx 26:     OK, {i1234 g0 tE=0s tA=0s {M0100644 SZ=0 L=0 0:0 B0*4096 i0:1234 A 0.000000 M 0.000000 C 0.000000}}
            20:50:18.492506 rx 28: GETATTR i1234 {Fh 0}
            20:50:18.492513 tx 28:     OK, {tA=0s {M0100644 SZ=0 L=0 0:0 B0*4096 i0:1234 A 0.000000 M 0.000000 C 0.000000}}
            20:50:18.492521 rx 30: GETATTR i1234 {Fh 0}
            20:50:18.492528 tx 30:     OK, {tA=0s {M0100644 SZ=0 L=0 0:0 B0*4096 i0:1234 A 0.000000 M 0.000000 C 0.000000}}
            20:50:18.492537 rx 32: LOOKUP i1 ["file"] 5b
            20:50:18.492545 tx 32:     OK, {i1234 g0 tE=0s tA=0s {M0100644 SZ=0 L=0 0:0 B0*4096 i0:1234 A 0.000000 M 0.000000 C 0.000000}}
            20:50:18.492555 rx 34: FORGET i18446744073709551615 {Nlookup=1}
            20:50:18.492575 rx 36: UNLINK i1 ["file"] 5b
            20:50:18.492588 tx 36:     OK
            20:50:18.492621 rx 38: LOOKUP i1 ["dir"] 4b
            [hangs here]
    
    Change-Id: Ibee48faf09c5a8993dfc7bb75251551f699cd63e
    da5ff9a7
bridge_test.go 3.59 KB