TrueCloudLab/frostfs-node
21
1
Fork 27
Code Issues 107 Pull requests 6 Projects Releases 2 Activity Actions

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
Member
Copy link

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
Copy link

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
Copy link

Can we close this?

Can we close this?
anikeev-yadro commented 2023-09-06 15:11:06 +00:00
Author
Member
Copy link

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.44
support/v0.42
support/v0.38
support/v0.37
support/v0.36
support/v0.34
support/v0.30
support/v0.27
v0.44.4
v0.42.18
v0.44.3
v0.44.2
v0.42.17
v0.44.1
v0.44.0
v0.44.0-rc.13
v0.44.0-rc.12
v0.44.0-rc.11
v0.42.16
v0.44.0-rc.10
v0.44.0-rc.9
v0.44.0-rc.8
v0.44.0-rc.7
v0.44.0-rc.6
v0.44.0-rc.5
v0.44.0-rc.4
v0.44.0-rc.3
v0.44.0-rc.2
v0.44.0-rc.1
v0.43.2
v0.43.1
v0.43.0
v0.42.15
v0.42.14
v0.42.13
v0.42.12
v0.42.11
v0.42.10
v0.42.9
v0.42.8
v0.42.7
v0.42.6
v0.42.5
v0.42.4
v0.42.3
v0.42.2
v0.42.1
v0.42.0
v0.42.0-rc.9
v0.42.0-rc.8
v0.42.0-rc.7
v0.38.9
v0.42.0-rc.6
v0.42.0-rc.5
v0.42.0-rc.4
v0.42.0-rc.3
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
v0.22.1
v0.22.0
v0.21.1
v0.21.0
v0.20.0
v0.19.0
v0.18.0
v0.17.0
v0.16.0
v0.15.0
v0.14.3
v0.14.2
v0.14.1
v0.14.0
v0.14.0-rc.1
v0.13.2
v0.13.1
v0.13.0
v0.13.0-rc.1
v0.12.1
v0.12.0
v0.12.0-rc3
v0.12.0-rc2
v0.12.0-rc1
v0.11.0
v0.10.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 labels
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
Projects
Clear projects
No items
No project
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
No description provided.
Delete branch "%!s()"

Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?