Panic due to failed assertion

[VihasMakwana]

We use bbolt in the filestorage extension of the OpenTelemetry Collector.

Recently, a few users have reported a panic occurring while running the Collector. It occurs during the bbolt.Open(..) call. Here's a stack trace:

panic: assertion failed: Page expected to be: 242, but self identifies as 8316213599780548146
goroutine 1 [running]:
go.etcd.io/bbolt._assert(...)
        go.etcd.io/bbolt@v1.3.10/db.go:1387
go.etcd.io/bbolt.(*page).fastCheck(0x7f795bd4c000, 0xf2)
        go.etcd.io/bbolt@v1.3.10/page.go:57 +0x1d9
go.etcd.io/bbolt.(*Tx).page(0xfd3f188?, 0x7412180?)
        go.etcd.io/bbolt@v1.3.10/tx.go:534 +0x7b
go.etcd.io/bbolt.(*Tx).forEachPageInternal(0xc002450540, {0xc00225b3b0, 0x2, 0xa}, 0xc00353e020)
        go.etcd.io/bbolt@v1.3.10/tx.go:546 +0x5d
go.etcd.io/bbolt.(*Tx).forEachPageInternal(0xc002450540, {0xc00225b3b0, 0x1, 0xa}, 0xc00353e020)
        go.etcd.io/bbolt@v1.3.10/tx.go:555 +0xc8
go.etcd.io/bbolt.(*Tx).forEachPage(...)
        go.etcd.io/bbolt@v1.3.10/tx.go:542
go.etcd.io/bbolt.(*Tx).checkBucket(0xc002450540, 0xc00187db80, 0xc00353e428, 0xc00353e368, {0x9f50fa8, 0x10095f80}, 0xc002259b00)
        go.etcd.io/bbolt@v1.3.10/tx_check.go:83 +0x114
go.etcd.io/bbolt.(*Tx).checkBucket.func2({0x7f795bca6020?, 0xc00225b360?, 0xc00347fa78?})
        go.etcd.io/bbolt@v1.3.10/tx_check.go:110 +0x90
go.etcd.io/bbolt.(*Bucket).ForEachBucket(0x0?, 0xc00353e220)
        go.etcd.io/bbolt@v1.3.10/bucket.go:411 +0x96
go.etcd.io/bbolt.(*Tx).checkBucket(0xc002450540, 0xc002450558, 0xc00353e428, 0xc00353e368, {0x9f50fa8, 0x10095f80}, 0xc002259b00)
        go.etcd.io/bbolt@v1.3.10/tx_check.go:108 +0x255
go.etcd.io/bbolt.(*DB).freepages(0xc002253448)
        go.etcd.io/bbolt@v1.3.10/db.go:1205 +0x225
go.etcd.io/bbolt.(*DB).loadFreelist.func1()
        go.etcd.io/bbolt@v1.3.10/db.go:417 +0xc5
sync.(*Once).doSlow(0x3fc8bc0?, 0xc002253610?)
        sync/once.go:74 +0xc2
sync.(*Once).Do(...)
        sync/once.go:65
go.etcd.io/bbolt.(*DB).loadFreelist(0xc002253448?)
        go.etcd.io/bbolt@v1.3.10/db.go:413 +0x45
go.etcd.io/bbolt.Open({0xc00225b2c0, 0x45}, 0x180, 0xc00353e650)

Related issues in opentelemetry-collector-contrib: open-telemetry/opentelemetry-collector-contrib#35899, open-telemetry/opentelemetry-collector-contrib#36840

[ahrtr]

Unfortunately, the db file is somehow corrupted. If you can provide the db file, we may try to help you to fix the corrupted db, but it isn't guaranteed.

[atoulme]

We are looking to use bbolt as an embedded store, and rather than panicking, it would be great if you could return an error so we don't have to catch the panic in a recover() block, which is fairly involved.

[ahrtr]

it would be great if you could return an error

Panicking means there is data corruption, which is hard for application to handle.

[VihasMakwana]

@ahrtr Would it be possible to fix this anonymous panic inside of a goroutine?

bbolt/db.go

Lines 1256 to 1260 in 7625e06

	go func() {
	for e := range ech {
	panic(fmt.Sprintf("freepages: failed to get all reachable pages (%v)", e))
	}
	}()

It is not possible to recover from it in parent process because the panic is inside of the goroutine.

If possible, I can raise a PR for this. Would you be open to review it?

[VihasMakwana]

Another panic trace. This happens due to a nil-pointer access:

go.etcd.io/bbolt.(*Bucket).Sequence(0x7eff026ea057?)
	go.etcd.io/bbolt@v1.3.11/bucket.go:346
go.etcd.io/bbolt.Compact.walk.func3.1({0x7eff026ea057, 0x15, 0x15}, 0x0)
	go.etcd.io/bbolt@v1.3.11/compact.go:94 +0x3c
go.etcd.io/bbolt.(*Tx).ForEach.func1({0x7eff026ea057, 0x15, 0x15}, {0x0?, 0x0?, 0x3fe0000000000000?})
	go.etcd.io/bbolt@v1.3.11/tx.go:131 +0x62
go.etcd.io/bbolt.(*Bucket).ForEach(0xffffffffffffffff?, 0xc001d1cd58)
	go.etcd.io/bbolt@v1.3.11/bucket.go:397 +0x90
go.etcd.io/bbolt.(*Tx).ForEach(0xc000c75f28?, 0xc001d1cda0?)
	go.etcd.io/bbolt@v1.3.11/tx.go:130 +0x45
go.etcd.io/bbolt.Compact.walk.func3(0x0?)
	go.etcd.io/bbolt@v1.3.11/compact.go:93 +0x33
go.etcd.io/bbolt.(*DB).View(0x3b9aca00?, 0xc001d1cea8)
	go.etcd.io/bbolt@v1.3.11/db.go:917 +0x72
go.etcd.io/bbolt.walk(...)
	go.etcd.io/bbolt@v1.3.11/compact.go:92
go.etcd.io/bbolt.Compact(0xc000954248, 0xc000c75d48, 0x10000)
	go.etcd.io/bbolt@v1.3.11/compact.go:21 +0x14c

[ahrtr]

@ahrtr Would it be possible to fix this anonymous panic inside of a goroutine?

bbolt/db.go

Lines 1256 to 1260 in 7625e06

go func() {
for e := range ech {
panic(fmt.Sprintf("freepages: failed to get all reachable pages (%v)", e))
}
}()
It is not possible to recover from it in parent process because the panic is inside of the goroutine.

If possible, I can raise a PR for this. Would you be open to review it?

It's the same reason as mentioned in #1011 (comment). Simply removing the panicking doesn't work. But I agree that we can change the implementation so that at least the applications can catch/recover it. We can execute the tx.recursivelyCheckBucket in a goroutine, and check the error channel in the caller's goroutine.

bbolt/db.go

Lines 1257 to 1259 in 7625e06

	for e := range ech {
	panic(fmt.Sprintf("freepages: failed to get all reachable pages (%v)", e))
	}

Another panic trace. This happens due to a nil-pointer access:

go.etcd.io/bbolt.(*Bucket).Sequence(0x7eff026ea057?)
	go.etcd.io/bbolt@v1.3.11/bucket.go:346
go.etcd.io/bbolt.Compact.walk.func3.1({0x7eff026ea057, 0x15, 0x15}, 0x0)
	go.etcd.io/bbolt@v1.3.11/compact.go:94 +0x3c
go.etcd.io/bbolt.(*Tx).ForEach.func1({0x7eff026ea057, 0x15, 0x15}, {0x0?, 0x0?, 0x3fe0000000000000?})
	go.etcd.io/bbolt@v1.3.11/tx.go:131 +0x62
go.etcd.io/bbolt.(*Bucket).ForEach(0xffffffffffffffff?, 0xc001d1cd58)
	go.etcd.io/bbolt@v1.3.11/bucket.go:397 +0x90
go.etcd.io/bbolt.(*Tx).ForEach(0xc000c75f28?, 0xc001d1cda0?)
	go.etcd.io/bbolt@v1.3.11/tx.go:130 +0x45
go.etcd.io/bbolt.Compact.walk.func3(0x0?)
	go.etcd.io/bbolt@v1.3.11/compact.go:93 +0x33
go.etcd.io/bbolt.(*DB).View(0x3b9aca00?, 0xc001d1cea8)
	go.etcd.io/bbolt@v1.3.11/db.go:917 +0x72
go.etcd.io/bbolt.walk(...)
	go.etcd.io/bbolt@v1.3.11/compact.go:92
go.etcd.io/bbolt.Compact(0xc000954248, 0xc000c75d48, 0x10000)
	go.etcd.io/bbolt@v1.3.11/compact.go:21 +0x14c

I did not get this. Do you mean the b is nil or b.bucket is nil? Could you provide detailed steps/info to reproduce this?

[VihasMakwana]

It's the same reason as mentioned in #1011 (comment). Simply removing the panicking doesn't work. But I agree that we can change the implementation so that at least the applications can catch/recover it. We can execute the tx.recursivelyCheckBucket in a goroutine, and check the error channel in the caller's goroutine.

Exactly. I had a similar implementation in my mind.
I can work on this and raise a PR for more reviews from the community.

I did not get this. Do you mean the b is nil or b.bucket is nil? Could you provide detailed steps/info to reproduce this?

I'm AFK right now but I'll provide more information on this soon.

[ahrtr]

Exactly. I had a similar implementation in my mind.
I can work on this and raise a PR for more reviews from the community.

Please feel free to deliver a PR for this, thx

[VihasMakwana]

@ahrtr Could you please reopen this? I'm planning to open up a PR for this.