TrueCloudLab
/
frostfs-node
18
1
Fork 20
Code Issues 88 Pull Requests 7 Actions Releases Activity

Panic while initializing corrupted blobovnica #662

New Issue
Closed
opened 2023-08-29 15:08:45 +00:00 by anikeev-yadro · 3 comments
anikeev-yadro commented 2023-08-29 15:08:45 +00:00

Expected Behavior

We should normally survive an unexpected restart of the server when power is lost.

Current Behavior

Node paniced while initializing corrupted blobovnica and not started.

Steps to Reproduce (for bugs)

  1. Start load on az, buky, glagoli
  2. Power off one node vedi
  3. After powered on the node was not restarted and cycling paniced
Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.004Z        info        frostfs-node/main.go:75        initializing profiler service...
Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.004Z        info        frostfs-node/main.go:77        profiler service has been successfully initialized
Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.004Z        info        frostfs-node/main.go:75        initializing metrics service...
Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.004Z        info        frostfs-node/main.go:77        metrics service has been successfully initialized
Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.004Z        info        frostfs-node/main.go:75        initializing tracing service...
Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.004Z        info        frostfs-node/main.go:77        tracing service has been successfully initialized
Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z        info        frostfs-node/config.go:919        shard attached to engine        {"id": "9wABzd7iMm68cRodSeHJRu"}
Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z        info        frostfs-node/config.go:919        shard attached to engine        {"id": "NjctRjn7doD8Fq8sWxEbHZ"}
Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z        info        frostfs-node/config.go:919        shard attached to engine        {"id": "BFMYejtMYm4MtoAmNiSNGZ"}
Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z        info        frostfs-node/config.go:919        shard attached to engine        {"id": "KDxV8ENb7WNdcdeAnYEPjj"}
Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z        info        frostfs-node/config.go:919        shard attached to engine        {"id": "W7kXaLjN9ftaRQDTRv1XWF"}
Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z        info        frostfs-node/config.go:919        shard attached to engine        {"id": "A3LyB2UuLaAEMWPVCvviYn"}
Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z        info        frostfs-node/config.go:919        shard attached to engine        {"id": "DhgHrn8uboEu1yMtSeffJg"}
Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z        info        frostfs-node/config.go:919        shard attached to engine        {"id": "J5gMJCKtb33zWdrsGL1jLf"}
Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z        info        frostfs-node/config.go:919        shard attached to engine        {"id": "225nvroDnzfiMrvptw8ggH"}
Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z        info        frostfs-node/config.go:919        shard attached to engine        {"id": "F8NuKKwzDTHVtVC3F8MJje"}
Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z        info        frostfs-node/config.go:919        shard attached to engine        {"id": "J3tB6vd8GQztR847cvSDs7"}
Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.006Z        info        frostfs-node/config.go:919        shard attached to engine        {"id": "NvgnMa2Cy4A5ARpHVwZwQ4"}
Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.006Z        info        frostfs-node/main.go:75        initializing storage engine service...
Aug 29 14:27:29 vedi frostfs-node[2845150]: panic: assertion failed: Page expected to be: 23521, but self identifies as 0
Aug 29 14:27:29 vedi frostfs-node[2845150]: goroutine 295 [running]:
Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt._assert(...)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         go.etcd.io/bbolt@v1.3.7/db.go:1359
Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt.(*page).fastCheck(0x7f7d39152000, 0x5be1)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         go.etcd.io/bbolt@v1.3.7/page.go:57 +0x1df
Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt.(*Tx).page(0x1fb9370?, 0x2?)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         go.etcd.io/bbolt@v1.3.7/tx.go:534 +0x8a
Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt.(*Tx).forEachPageInternal(0x1fb9578?, {0xc000624550?, 0x3, 0xa}, 0xc0007b9348)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         go.etcd.io/bbolt@v1.3.7/tx.go:546 +0x65
Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt.(*Tx).forEachPageInternal(0x3?, {0xc000624550?, 0x2, 0xa}, 0xc0007b9348)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         go.etcd.io/bbolt@v1.3.7/tx.go:555 +0xd5
Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt.(*Tx).forEachPageInternal(0xc0001036c0?, {0xc000624550?, 0x1, 0xa}, 0xc0007b9348)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         go.etcd.io/bbolt@v1.3.7/tx.go:555 +0xd5
Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt.(*Tx).forEachPage(...)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         go.etcd.io/bbolt@v1.3.7/tx.go:542
Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt.(*Bucket).forEachPage(0xc001fa2180?, 0xc0007b9348)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         go.etcd.io/bbolt@v1.3.7/bucket.go:502 +0xbe
Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt.(*Bucket).Stats(0xc0007b9460?)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         go.etcd.io/bbolt@v1.3.7/bucket.go:419 +0x11d
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza.(*Blobovnicza).initializeCounters.func1.1(0xc000714b78?, 0x20000, 0x3?)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza/control.go:109 +0x4e
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza.(*Blobovnicza).iterateAllBuckets.func1(0x0?, 0x7f7ec7772978?, {0xc000622c90?, 0x8?, 0xc000780400?})
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza/iterate.go:26 +0x65
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza.(*Blobovnicza).iterateBucketKeys.func1(0x8?, 0x20000)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza/iterate.go:32 +0x99
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza.(*Blobovnicza).iterateBounds(0x0?, 0x1?, 0xc0007b9548)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza/iterate.go:49 +0xcc
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza.(*Blobovnicza).iterateBucketKeys(0xc0004f3440?, 0x0?, 0x5c12?)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza/iterate.go:31 +0x35
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza.(*Blobovnicza).iterateAllBuckets(0xc000714b60?, 0xc0004f3600?, 0xc0004f3620?)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza/iterate.go:20 +0x45
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza.(*Blobovnicza).initializeCounters.func1(0x40babd?)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza/control.go:108 +0x55
Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt.(*DB).View(0xc0007b96b8?, 0xc0007b9698)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         go.etcd.io/bbolt@v1.3.7/db.go:893 +0x82
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza.(*Blobovnicza).initializeCounters(0xc000300230)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza/control.go:107 +0x71
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza.(*Blobovnicza).Init(0xc000300230)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza/control.go:101 +0x472
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree.(*Blobovniczas).openBlobovniczaNoCache(0xc00044a6e0, {0xc000622a48, 0x5})
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree/control.go:139 +0x3ea
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree.(*Blobovniczas).Init.func1({0xc000622a48, 0x5})
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree/control.go:32 +0x6c
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree.(*Blobovniczas).iterateSortedLeaves.func1({0xc0004de500?, 0xc0004da240?, 0xa?})
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree/iterate.go:92 +0x31
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree.(*Blobovniczas).iterateSorted(0xc00044a6e0, {0x1651898, 0xc000126008}, 0x0?, {0xc0004e02c0, 0x2, 0x2}, 0x2, 0xc0007b9cf8)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree/iterate.go:142 +0x33c
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree.(*Blobovniczas).iterateSorted(0xc00044a6e0, {0x1651898, 0xc000126008}, 0xc0004e02c0?, {0xc0004e02c0, 0x1, 0x2}, 0x2, 0xc0007b9cf8)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree/iterate.go:147 +0x385
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree.(*Blobovniczas).iterateSorted(0xc00044a6e0, {0x1651898, 0xc000126008}, 0x0?, {0xc0004e02c0, 0x0, 0x2}, 0x2, 0xc0007b9cf8)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree/iterate.go:147 +0x385
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree.(*Blobovniczas).iterateSortedLeaves(0xc00044a6e0, {0x1651898, 0xc000126008}, 0x0?, 0xc0006dcd48)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree/iterate.go:87 +0x9d
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree.(*Blobovniczas).iterateLeaves(...)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree/iterate.go:159
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree.(*Blobovniczas).Init(0xc00044a6e0)
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree/control.go:31 +0xa6
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor.(*BlobStor).Init(0xc00072b900)
Aug 29 14:27:29 vedi audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=unconfined msg='unit=frostfs-storage comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/control.go:41 +0xb5
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/shard.(*Shard).Init(0xc00019fb90, {0x1651860, 0xc000137e00})
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/shard/control.go:124 +0x2f6
Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/engine.(*StorageEngine).Init.func1()
Aug 29 14:27:29 vedi frostfs-node[2845150]:         git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/engine/control.go:88 +0x45
Aug 29 14:27:29 vedi frostfs-node[2845150]: golang.org/x/sync/errgroup.(*Group).Go.func1()
Aug 29 14:27:29 vedi frostfs-node[2845150]:         golang.org/x/sync@v0.3.0/errgroup/errgroup.go:75 +0x64
Aug 29 14:27:29 vedi frostfs-node[2845150]: created by golang.org/x/sync/errgroup.(*Group).Go
Aug 29 14:27:29 vedi frostfs-node[2845150]:         golang.org/x/sync@v0.3.0/errgroup/errgroup.go:72 +0xa5
Aug 29 14:27:29 vedi systemd[1]: frostfs-storage.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Aug 29 14:27:29 vedi systemd[1]: frostfs-storage.service: Failed with result 'exit-code'.
Aug 29 14:27:29 vedi kernel: audit: type=1131 audit(1693319249.030:331642): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=unconfined msg='unit=frostfs-storage comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Aug 29 14:27:29 vedi systemd[1]: Reloading.
Aug 29 14:27:29 vedi systemd-fstab-generator[2845235]: Ignoring "nofail" option for root device

Context

Failover tests with load on 3 nodes and reboot 4th node.

Regression

Yes

Version

FrostFS Storage node
Version: v0.0.1-848-g238b8f10
GoVersion: go1.20.5

Your Environment

HW
4 nodes

## Expected Behavior We should normally survive an unexpected restart of the server when power is lost. ## Current Behavior Node paniced while initializing corrupted blobovnica and not started. ## Steps to Reproduce (for bugs) 1. Start load on `az, buky, glagoli` 2. Power off one node `vedi` 3. After powered on the node was not restarted and cycling paniced ``` Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.004Z info frostfs-node/main.go:75 initializing profiler service... Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.004Z info frostfs-node/main.go:77 profiler service has been successfully initialized Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.004Z info frostfs-node/main.go:75 initializing metrics service... Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.004Z info frostfs-node/main.go:77 metrics service has been successfully initialized Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.004Z info frostfs-node/main.go:75 initializing tracing service... Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.004Z info frostfs-node/main.go:77 tracing service has been successfully initialized Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z info frostfs-node/config.go:919 shard attached to engine {"id": "9wABzd7iMm68cRodSeHJRu"} Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z info frostfs-node/config.go:919 shard attached to engine {"id": "NjctRjn7doD8Fq8sWxEbHZ"} Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z info frostfs-node/config.go:919 shard attached to engine {"id": "BFMYejtMYm4MtoAmNiSNGZ"} Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z info frostfs-node/config.go:919 shard attached to engine {"id": "KDxV8ENb7WNdcdeAnYEPjj"} Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z info frostfs-node/config.go:919 shard attached to engine {"id": "W7kXaLjN9ftaRQDTRv1XWF"} Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z info frostfs-node/config.go:919 shard attached to engine {"id": "A3LyB2UuLaAEMWPVCvviYn"} Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z info frostfs-node/config.go:919 shard attached to engine {"id": "DhgHrn8uboEu1yMtSeffJg"} Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z info frostfs-node/config.go:919 shard attached to engine {"id": "J5gMJCKtb33zWdrsGL1jLf"} Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z info frostfs-node/config.go:919 shard attached to engine {"id": "225nvroDnzfiMrvptw8ggH"} Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z info frostfs-node/config.go:919 shard attached to engine {"id": "F8NuKKwzDTHVtVC3F8MJje"} Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.005Z info frostfs-node/config.go:919 shard attached to engine {"id": "J3tB6vd8GQztR847cvSDs7"} Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.006Z info frostfs-node/config.go:919 shard attached to engine {"id": "NvgnMa2Cy4A5ARpHVwZwQ4"} Aug 29 14:27:29 vedi frostfs-node[2845150]: 2023-08-29T14:27:29.006Z info frostfs-node/main.go:75 initializing storage engine service... Aug 29 14:27:29 vedi frostfs-node[2845150]: panic: assertion failed: Page expected to be: 23521, but self identifies as 0 Aug 29 14:27:29 vedi frostfs-node[2845150]: goroutine 295 [running]: Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt._assert(...) Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt@v1.3.7/db.go:1359 Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt.(*page).fastCheck(0x7f7d39152000, 0x5be1) Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt@v1.3.7/page.go:57 +0x1df Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt.(*Tx).page(0x1fb9370?, 0x2?) Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt@v1.3.7/tx.go:534 +0x8a Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt.(*Tx).forEachPageInternal(0x1fb9578?, {0xc000624550?, 0x3, 0xa}, 0xc0007b9348) Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt@v1.3.7/tx.go:546 +0x65 Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt.(*Tx).forEachPageInternal(0x3?, {0xc000624550?, 0x2, 0xa}, 0xc0007b9348) Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt@v1.3.7/tx.go:555 +0xd5 Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt.(*Tx).forEachPageInternal(0xc0001036c0?, {0xc000624550?, 0x1, 0xa}, 0xc0007b9348) Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt@v1.3.7/tx.go:555 +0xd5 Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt.(*Tx).forEachPage(...) Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt@v1.3.7/tx.go:542 Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt.(*Bucket).forEachPage(0xc001fa2180?, 0xc0007b9348) Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt@v1.3.7/bucket.go:502 +0xbe Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt.(*Bucket).Stats(0xc0007b9460?) Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt@v1.3.7/bucket.go:419 +0x11d Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza.(*Blobovnicza).initializeCounters.func1.1(0xc000714b78?, 0x20000, 0x3?) Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza/control.go:109 +0x4e Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza.(*Blobovnicza).iterateAllBuckets.func1(0x0?, 0x7f7ec7772978?, {0xc000622c90?, 0x8?, 0xc000780400?}) Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza/iterate.go:26 +0x65 Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza.(*Blobovnicza).iterateBucketKeys.func1(0x8?, 0x20000) Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza/iterate.go:32 +0x99 Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza.(*Blobovnicza).iterateBounds(0x0?, 0x1?, 0xc0007b9548) Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza/iterate.go:49 +0xcc Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza.(*Blobovnicza).iterateBucketKeys(0xc0004f3440?, 0x0?, 0x5c12?) Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza/iterate.go:31 +0x35 Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza.(*Blobovnicza).iterateAllBuckets(0xc000714b60?, 0xc0004f3600?, 0xc0004f3620?) Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza/iterate.go:20 +0x45 Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza.(*Blobovnicza).initializeCounters.func1(0x40babd?) Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza/control.go:108 +0x55 Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt.(*DB).View(0xc0007b96b8?, 0xc0007b9698) Aug 29 14:27:29 vedi frostfs-node[2845150]: go.etcd.io/bbolt@v1.3.7/db.go:893 +0x82 Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza.(*Blobovnicza).initializeCounters(0xc000300230) Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza/control.go:107 +0x71 Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza.(*Blobovnicza).Init(0xc000300230) Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobovnicza/control.go:101 +0x472 Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree.(*Blobovniczas).openBlobovniczaNoCache(0xc00044a6e0, {0xc000622a48, 0x5}) Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree/control.go:139 +0x3ea Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree.(*Blobovniczas).Init.func1({0xc000622a48, 0x5}) Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree/control.go:32 +0x6c Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree.(*Blobovniczas).iterateSortedLeaves.func1({0xc0004de500?, 0xc0004da240?, 0xa?}) Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree/iterate.go:92 +0x31 Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree.(*Blobovniczas).iterateSorted(0xc00044a6e0, {0x1651898, 0xc000126008}, 0x0?, {0xc0004e02c0, 0x2, 0x2}, 0x2, 0xc0007b9cf8) Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree/iterate.go:142 +0x33c Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree.(*Blobovniczas).iterateSorted(0xc00044a6e0, {0x1651898, 0xc000126008}, 0xc0004e02c0?, {0xc0004e02c0, 0x1, 0x2}, 0x2, 0xc0007b9cf8) Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree/iterate.go:147 +0x385 Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree.(*Blobovniczas).iterateSorted(0xc00044a6e0, {0x1651898, 0xc000126008}, 0x0?, {0xc0004e02c0, 0x0, 0x2}, 0x2, 0xc0007b9cf8) Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree/iterate.go:147 +0x385 Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree.(*Blobovniczas).iterateSortedLeaves(0xc00044a6e0, {0x1651898, 0xc000126008}, 0x0?, 0xc0006dcd48) Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree/iterate.go:87 +0x9d Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree.(*Blobovniczas).iterateLeaves(...) Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree/iterate.go:159 Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree.(*Blobovniczas).Init(0xc00044a6e0) Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/blobovniczatree/control.go:31 +0xa6 Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor.(*BlobStor).Init(0xc00072b900) Aug 29 14:27:29 vedi audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=unconfined msg='unit=frostfs-storage comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed' Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/blobstor/control.go:41 +0xb5 Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/shard.(*Shard).Init(0xc00019fb90, {0x1651860, 0xc000137e00}) Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/shard/control.go:124 +0x2f6 Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/engine.(*StorageEngine).Init.func1() Aug 29 14:27:29 vedi frostfs-node[2845150]: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/engine/control.go:88 +0x45 Aug 29 14:27:29 vedi frostfs-node[2845150]: golang.org/x/sync/errgroup.(*Group).Go.func1() Aug 29 14:27:29 vedi frostfs-node[2845150]: golang.org/x/sync@v0.3.0/errgroup/errgroup.go:75 +0x64 Aug 29 14:27:29 vedi frostfs-node[2845150]: created by golang.org/x/sync/errgroup.(*Group).Go Aug 29 14:27:29 vedi frostfs-node[2845150]: golang.org/x/sync@v0.3.0/errgroup/errgroup.go:72 +0xa5 Aug 29 14:27:29 vedi systemd[1]: frostfs-storage.service: Main process exited, code=exited, status=2/INVALIDARGUMENT Aug 29 14:27:29 vedi systemd[1]: frostfs-storage.service: Failed with result 'exit-code'. Aug 29 14:27:29 vedi kernel: audit: type=1131 audit(1693319249.030:331642): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=unconfined msg='unit=frostfs-storage comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed' Aug 29 14:27:29 vedi systemd[1]: Reloading. Aug 29 14:27:29 vedi systemd-fstab-generator[2845235]: Ignoring "nofail" option for root device ``` ## Context Failover tests with load on 3 nodes and reboot 4th node. ## Regression Yes ## Version ``` FrostFS Storage node Version: v0.0.1-848-g238b8f10 GoVersion: go1.20.5 ``` ## Your Environment HW 4 nodes
anikeev-yadro added the
bug
triage
 labels 2023-08-29 15:08:45 +00:00
fyrchik self-assigned this 2023-08-30 06:08:09 +00:00
fyrchik commented 2023-08-30 12:46:20 +00:00
Owner

The last 64 pages were empty (0x00). It could be related to database grow an 1.3.7 has related changes (https://github.com/etcd-io/bbolt/pull/387/). Also when I remove the cause of the panic bbolt check tells me these pages are neigher free no used.
Let's first try reverting bolt version and then investigating problem on 1.3.7.

The last 64 pages were empty (0x00). It could be related to database grow an 1.3.7 has related changes (https://github.com/etcd-io/bbolt/pull/387/). Also when I remove the cause of the panic `bbolt check` tells me these pages are neigher free no used. Let's first try reverting bolt version and then investigating problem on 1.3.7.
fyrchik added this to the v0.37.0 milestone 2023-08-30 12:57:26 +00:00
fyrchik commented 2023-09-06 08:06:49 +00:00
Owner

Can we close this?

Can we close this?
anikeev-yadro commented 2023-09-06 15:11:06 +00:00
Poster

No, we need more time for testing

No, we need more time for testing
Sign in to join this conversation.
No Branch/Tag Specified
Branches Tags
master
support/v0.38
support/v0.37
support/v0.36
support/v0.34
support/v0.30
support/v0.27
v0.42.0-rc.2
v0.42.0-rc.1
v0.38.8
v0.41.0
v0.38.7
v0.40.0
v0.39.0
v0.38.6
v0.38.5
v0.38.4
v0.38.3
v0.38.2
v0.38.1
v0.38.0
v0.38.0-rc.2
v0.38.0-rc.1
v0.37.0
v0.37.0-rc.1
v0.36.0
v0.34.0
Labels
Clear labels   
P0

Highest   
P1

High   
P2

Medium   
P3

Low   
badger

Badger DB related issues   
frostfs-adm
   
frostfs-cli
   
frostfs-ir
   
frostfs-lens
   
frostfs-node
   
good first issue

Good for newcomers   
triage
  
Infrastructure

Infrastructure, Automation, CI/CD or DevOps related stuff   
blocked

The issue or PR is blocked by something   
bug

Something is not working   
config

Configuration format update or breaking change   
discussion

Talking about something in order to reach a decision or to exchange ideas   
documentation

Documentation related   
duplicate

This issue or pull request already exists   
enhancement

New feature   
go

Language features adoption   
help wanted

Extra attention is needed   
internal
   
invalid

Something is wrong   
kludge

This is a kludge and we know it   
observability

Related to metrics, tracing and logs   
perfomance

Perfomance related   
question

More information is needed   
refactoring

Refactoring   
wontfix

This won't be fixed
No Label
P0
P1
P2
P3
badger
frostfs-adm
frostfs-cli
frostfs-ir
frostfs-lens
frostfs-node
good first issue
triage
Infrastructure
blocked
bug
config
discussion
documentation
duplicate
enhancement
go
help wanted
internal
invalid
kludge
observability
perfomance
question
refactoring
wontfix
Milestone
Clear milestone
No items
No Milestone
v0.37.0
Assignees
Clear assignees
No Assignees
fyrchik
2 Participants
Notifications
Due Date
The due date is invalid or out of range. Please use the format 'yyyy-mm-dd'.

No due date set.

Dependencies

No dependencies set.

Reference: TrueCloudLab/frostfs-node#662
There is no content yet.
Delete Branch "%!s(<nil>)"

Deleting a branch is permanent. Although the deleted branch may exist for a short time before cleaning up, in most cases it CANNOT be undone. Continue?