Commit 38dde766 authored by Kirill Smelkov's avatar Kirill Smelkov

wcfs: Fix crash if on watch request setupWatch needs to access ZODB

The problem is similar to a7bf0311 (wcfs: Fix crash if on invalidation
handledδZ needs to access ZODB) - I forgot to put zhead's transaction into
context.

Without the fix added test fails as:

    wcfs_test.py::test_wcfs_crash_old_data
    ---------------- live log call -----------------
    WARNING  ZODB.FileStorage:FileStorage.py:413 Ignoring index for /tmp/testdb_fs.OV0rS6/1.fs

    M: commit -> @at0 (03e5a3342bc5ab22)

    M: commit -> @at1 (03e5a3342bc88899)
    M:      f<0000000000000002>     [0]
    INFO     wcfs:__init__.py:293 starting for file:///tmp/testdb_fs.OV0rS6/1.fs ...
    I0120 17:12:10.274379  704327 wcfs.go:2393] start "/dev/shm/wcfs/556fa61a9f9675f34c6b44e1f978842c37176c59" "file:///tmp/testdb_fs.OV0rS6/1.fs"
    I0120 17:12:10.274409  704327 wcfs.go:2399] (built with go1.17.6)
    W0120 17:12:10.274560  704327 storage.go:152] zodb: FIXME: open file:///tmp/testdb_fs.OV0rS6/1.fs: raw cache is not ready for invalidations -> NoCache forced
    INFO     wcfs:__init__.py:334 started pid704327 @ /dev/shm/wcfs/556fa61a9f9675f34c6b44e1f978842c37176c59

    C: setup watch f<0000000000000002> @at1 (03e5a3342bc88899)
    #  pinok: {}

    M: commit -> @at2 (03e5a3342c895777)
    M:      f<0000000000000002>     [1]

    M: commit -> @at3 (03e5a3342ca5ef55)
    M:      f<0000000000000002>     [0]

    C: setup watch f<0000000000000002> @at2 (03e5a3342c895777)
    #  pinok: {0: @at1 (03e5a3342bc88899)}
    panic: transaction: no current transaction

    goroutine 88 [running]:
    lab.nexedi.com/kirr/neo/go/transaction.currentTxn({0x969718, 0xc0000b6240})
            /home/kirr/src/neo/src/lab.nexedi.com/kirr/neo/go/transaction/transaction.go:59 +0x77
    lab.nexedi.com/kirr/neo/go/transaction.Current(...)
            /home/kirr/src/neo/src/lab.nexedi.com/kirr/neo/go/transaction/api.go:206
    lab.nexedi.com/kirr/neo/go/zodb.(*Connection).checkTxnCtx(...)
            /home/kirr/src/neo/src/lab.nexedi.com/kirr/neo/go/zodb/connection.go:374
    lab.nexedi.com/kirr/neo/go/zodb.(*Connection).Get(0xc0000c25a0, {0x969718, 0xc0000b6240}, 0x4)
            /home/kirr/src/neo/src/lab.nexedi.com/kirr/neo/go/zodb/connection.go:331 +0x73
    lab.nexedi.com/nexedi/wendelin.core/wcfs/internal/zdata.(*ΔFtail).BlkRevAt(0xc00009dd40, {0x969718, 0xc0000b6240}, 0xc000100540, 0x30, 0x3e5a3342c895777)
            /home/kirr/src/neo/src/lab.nexedi.com/nexedi/wendelin.core/wcfs/internal/zdata/δftail.go:1140 +0x39d
    main.(*WatchLink).setupWatch(0xc0000120a0, {0x969718, 0xc0000b6240}, 0x2, 0x3e5a3342c895777)
            /home/kirr/src/neo/src/lab.nexedi.com/nexedi/wendelin.core/wcfs/wcfs.go:1754 +0xe3f
    main.(*WatchLink)._handleWatch(0x0, {0x969718, 0xc0000b6240}, {0xc0000a0122, 0x0})
            /home/kirr/src/neo/src/lab.nexedi.com/nexedi/wendelin.core/wcfs/wcfs.go:1973 +0x65
    main.(*WatchLink).handleWatch(0x0, {0x969718, 0xc0000b6240}, 0x0, {0xc0000a0122, 0x28})
            /home/kirr/src/neo/src/lab.nexedi.com/nexedi/wendelin.core/wcfs/wcfs.go:1955 +0x10c
    main.(*WatchLink)._serve.func3({0x969718, 0xc0000b6240})
            /home/kirr/src/neo/src/lab.nexedi.com/nexedi/wendelin.core/wcfs/wcfs.go:1944 +0x3c
    lab.nexedi.com/kirr/go123/xsync.(*WorkGroup).Go.func1()
            /home/kirr/src/neo/src/lab.nexedi.com/kirr/go123/xsync/xsync.go:86 +0x68
    created by lab.nexedi.com/kirr/go123/xsync.(*WorkGroup).Go
            /home/kirr/src/neo/src/lab.nexedi.com/kirr/go123/xsync/xsync.go:83 +0x92
    >>> Change history by file:

    f<0000000000000002>:
                                    0 1 2 3 4 5 6 7
                                    a b c d e f g h
            @at0 (03e5a3342bc5ab22)
            @at1 (03e5a3342bc88899) 0
            @at2 (03e5a3342c895777)   1
            @at3 (03e5a3342ca5ef55) 0

    ----------------------------------------

            # wcfs was crashing in setting up watch because of "1" and "2" from above, and
            # 3. setupWatch was calling ΔFtail.BlkRevAt without putting zhead's transaction into ctx.
            wl2 = t.openwatch()
    >       wl2.watch(zf, at2, {0:at1})
parent ca3e54e2
......@@ -1613,6 +1613,10 @@ func (wlink *WatchLink) setupWatch(ctx context.Context, foid zodb.Oid, at zodb.T
defer head.zheadMu.RUnlock()
headAt := head.zconn.At()
// TODO better ctx = transaction.PutIntoContext(ctx, txn)
ctx, cancel := xcontext.Merge(ctx, head.zconn.TxnCtx)
defer cancel()
if at != zodb.InvalidTid && at < bfdir.δFtail.Tail() {
return fmt.Errorf("too far away back from head/at (@%s); δt = %s",
headAt, headAt.Time().Sub(at.Time().Time))
......
......@@ -1844,15 +1844,20 @@ def test_wcfs_crash_old_data():
at2 = t.commit(zf, {1:'b1'}) # arbitrary commit to non-0 blk
# wcfs was crashing on processing invalidation to blk 0 because
# - ΔBtail.GetAt([0], head) returns valueExact=false, and so
# - ΔFtail.BlkRevAt activates "access ZODB" codepath,
# - but handleδZ was calling ΔFtail.BlkRevAt without properly putting zhead's transaction into ctx.
# 1. ΔBtail.GetAt([0], head) returns valueExact=false, and so
# 2. ΔFtail.BlkRevAt activates "access ZODB" codepath,
# 3. but handleδZ was calling ΔFtail.BlkRevAt without putting zhead's transaction into ctx.
# -> panic.
t.commit(zf, {0:'a2'})
at3 = t.commit(zf, {0:'a2'})
# just in case
f.assertBlk(0, 'a2')
# wcfs was crashing in setting up watch because of "1" and "2" from above, and
# 3. setupWatch was calling ΔFtail.BlkRevAt without putting zhead's transaction into ctx.
wl2 = t.openwatch()
wl2.watch(zf, at2, {0:at1})
# ---- misc ---
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment