Skip to content

leveldb.(*DB).Close() took too much time to finish #434

New issue
New issue
Open
Open
leveldb.(*DB).Close() took too much time to finish#434
@brilliant-lx

Description

@brilliant-lx
brilliant-lx
opened on Jun 7, 2023

Description

BSC recently upgrade the goleveldb version indirectly to the latest commit, i.e. from: 20210819022825-2ae1ddf74ef7 to 20220721030215-126854af5e6d

When we tried to restart the node, it took quite a long time, more several minutes, eventually force killed.
After some investigation, we found the node got stuck on leveldb.(*DB).Close(), the database is quite large on BSC. But it was ok with an older version. Dive deeper, we found it was caused by the levelDB upgrade, after downgrade to the previous version, the issue is gone.

Some Information to share:

  • The size of the database is ~2.5TB
  • some of the call stack dumped during DB close
//== dump 1: 
goroutine 18035443 [runnable]:
github.com/syndtr/goleveldb/leveldb/cache.(*lru).Evict(0xc002b104c0?, 0xc06977fa40?)
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/cache/lru.go:138 +0x175
github.com/syndtr/goleveldb/leveldb/cache.(*Cache).Close.func1({0xc26ac58000, 0x131ce, 0xc1481f3b60?})
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/cache/cache.go:661 +0x7f

github.com/syndtr/goleveldb/leveldb/cache.(*mHead).enumerateNodesWithCB(0xc144998380, 0xc1ddfb3b98)
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/cache/cache.go:327 +0x58
github.com/syndtr/goleveldb/leveldb/cache.(*Cache).Close(0xc0018823f0, 0x1)
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/cache/cache.go:652 +0xb0
github.com/syndtr/goleveldb/leveldb.(*tOps).close(0xc002b0e690)
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/table.go:494 +0x2a
github.com/syndtr/goleveldb/leveldb.(*session).close(0xc001ed4e10)
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/session.go:101 +0x29
github.com/syndtr/goleveldb/leveldb.(*DB).Close(0x17?)
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db.go:1218 +0x2b4

github.com/ethereum/go-ethereum/ethdb/leveldb.(*Database).Close(0xc002252200)
        /home/runner/work/bsc/bsc/ethdb/leveldb/leveldb.go:180 +0x205
github.com/ethereum/go-ethereum/core/rawdb.(*freezerdb).Close(0xc0018f45a0)
        /home/runner/work/bsc/bsc/core/rawdb/database.go:50 +0xd0
github.com/ethereum/go-ethereum/node.(*closeTrackingDB).Close(0xc0002827c8)
        /home/runner/work/bsc/bsc/node/node.go:698 +0x99
github.com/ethereum/go-ethereum/eth.(*Ethereum).Stop(0xc0002a6360)
        /home/runner/work/bsc/bsc/eth/backend.go:684 +0x158
github.com/ethereum/go-ethereum/node.(*Node).stopServices(0xc00228c410, {0xc01dfece40, 0x2, 0x3be62318a99cbdfe?})
        /home/runner/work/bsc/bsc/node/node.go:321 +0xbd
github.com/ethereum/go-ethereum/node.(*Node).Close(0xc00228c410)
        /home/runner/work/bsc/bsc/node/node.go:241 +0x191
created by github.com/ethereum/go-ethereum/cmd/utils.StartNode.func1.1
        /home/runner/work/bsc/bsc/cmd/utils/cmd.go:92 +0x96


//== dump 2: 17s
goroutine 18035443 [runnable]:
github.com/syndtr/goleveldb/leveldb/cache.(*Node).callFinalizer(0xc1ca643b20)
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/cache/cache.go:722 +0xf9
github.com/syndtr/goleveldb/leveldb/cache.(*Cache).Close.func1({0xc273374000, 0x2190f, 0xc1481f3b60?})
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/cache/cache.go:665 +0xae

github.com/syndtr/goleveldb/leveldb/cache.(*mHead).enumerateNodesWithCB(0xc144998380, 0xc1ddfb3b98)
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/cache/cache.go:327 +0x58
github.com/syndtr/goleveldb/leveldb/cache.(*Cache).Close(0xc0018823f0, 0x1)
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/cache/cache.go:652 +0xb0
github.com/syndtr/goleveldb/leveldb.(*tOps).close(0xc002b0e690)
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/table.go:494 +0x2a
github.com/syndtr/goleveldb/leveldb.(*session).close(0xc001ed4e10)
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/session.go:101 +0x29
github.com/syndtr/goleveldb/leveldb.(*DB).Close(0x17?)
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db.go:1218 +0x2b4

github.com/ethereum/go-ethereum/ethdb/leveldb.(*Database).Close(0xc002252200)
        /home/runner/work/bsc/bsc/ethdb/leveldb/leveldb.go:180 +0x205
github.com/ethereum/go-ethereum/core/rawdb.(*freezerdb).Close(0xc0018f45a0)
        /home/runner/work/bsc/bsc/core/rawdb/database.go:50 +0xd0
github.com/ethereum/go-ethereum/node.(*closeTrackingDB).Close(0xc0002827c8)
        /home/runner/work/bsc/bsc/node/node.go:698 +0x99
github.com/ethereum/go-ethereum/eth.(*Ethereum).Stop(0xc0002a6360)
        /home/runner/work/bsc/bsc/eth/backend.go:684 +0x158
github.com/ethereum/go-ethereum/node.(*Node).stopServices(0xc00228c410, {0xc01dfece40, 0x2, 0x3be62318a99cbdfe?})
        /home/runner/work/bsc/bsc/node/node.go:321 +0xbd
github.com/ethereum/go-ethereum/node.(*Node).Close(0xc00228c410)
        /home/runner/work/bsc/bsc/node/node.go:241 +0x191
created by github.com/ethereum/go-ethereum/cmd/utils.StartNode.func1.1
        /home/runner/work/bsc/bsc/cmd/utils/cmd.go:92 +0x96


//== dump 3: after 70s
goroutine 18035443 [runnable]:
github.com/syndtr/goleveldb/leveldb/cache.(*Node).callFinalizer(0xc03d4843f0)
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/cache/cache.go:722 +0xf9
github.com/syndtr/goleveldb/leveldb/cache.(*Cache).Close.func1({0xc299162000, 0x3b882, 0x39c00?})
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/cache/cache.go:665 +0xae

github.com/syndtr/goleveldb/leveldb/cache.(*mHead).enumerateNodesWithCB(0xc144998380, 0xc1ddfb3b98)
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/cache/cache.go:327 +0x58
github.com/syndtr/goleveldb/leveldb/cache.(*Cache).Close(0xc0018823f0, 0x1)
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/cache/cache.go:652 +0xb0
github.com/syndtr/goleveldb/leveldb.(*tOps).close(0xc002b0e690)
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/table.go:494 +0x2a
github.com/syndtr/goleveldb/leveldb.(*session).close(0xc001ed4e10)
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/session.go:101 +0x29
github.com/syndtr/goleveldb/leveldb.(*DB).Close(0x17?)
        /home/runner/go/pkg/mod/github.com/syndtr/[email protected]/leveldb/db.go:1218 +0x2b4

github.com/ethereum/go-ethereum/ethdb/leveldb.(*Database).Close(0xc002252200)
        /home/runner/work/bsc/bsc/ethdb/leveldb/leveldb.go:180 +0x205
github.com/ethereum/go-ethereum/core/rawdb.(*freezerdb).Close(0xc0018f45a0)
        /home/runner/work/bsc/bsc/core/rawdb/database.go:50 +0xd0
github.com/ethereum/go-ethereum/node.(*closeTrackingDB).Close(0xc0002827c8)
        /home/runner/work/bsc/bsc/node/node.go:698 +0x99
github.com/ethereum/go-ethereum/eth.(*Ethereum).Stop(0xc0002a6360)
        /home/runner/work/bsc/bsc/eth/backend.go:684 +0x158
github.com/ethereum/go-ethereum/node.(*Node).stopServices(0xc00228c410, {0xc01dfece40, 0x2, 0x3be62318a99cbdfe?})
        /home/runner/work/bsc/bsc/node/node.go:321 +0xbd
github.com/ethereum/go-ethereum/node.(*Node).Close(0xc00228c410)
        /home/runner/work/bsc/bsc/node/node.go:241 +0x191
created by github.com/ethereum/go-ethereum/cmd/utils.StartNode.func1.1
        /home/runner/work/bsc/bsc/cmd/utils/cmd.go:92 +0x96

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions