Skip to content

Commit 8870429

Browse files
committed
fix(network-fabric): propagate ledger info failures instead of rescanning from genesis
Signed-off-by: AkramBitar <akram@il.ibm.com>
1 parent 94c21c2 commit 8870429

3 files changed

Lines changed: 319 additions & 9 deletions

File tree

docs/services/network-fabric.md

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -294,6 +294,20 @@ sequenceDiagram
294294
- LRU cache for recent transactions
295295
- Automatic retry on connection failures
296296

297+
#### Choosing the Starting Block
298+
299+
The scan resumes at the peer's current ledger height, read via `GetLedgerInfo`
300+
([`delivery.go`](../../token/services/network/fabric/finality/delivery.go)). Because that
301+
one RPC decides the starting block, a failure is retried with an exponentially growing
302+
delay (`LedgerInfoAttempts`, `LedgerInfoRetryDelay`; 3 attempts over ~1.5s by default) and
303+
aborts early if the context is cancelled.
304+
305+
If the height is still unavailable after the last attempt, `ScanBlock` returns the error
306+
rather than defaulting to block 0. Starting at genesis would rescan the entire chain and
307+
replay finality notifications for every historical transaction, while the caller would have
308+
no way to tell a transient RPC failure from a genuinely fresh chain. Block 0 is used only
309+
when no ledger is configured at all.
310+
297311
### Notification Mode
298312

299313
Uses asynchronous event notifications from the FSC layer:

token/services/network/fabric/finality/delivery.go

Lines changed: 95 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -8,27 +8,113 @@ package finality
88

99
import (
1010
"context"
11+
"time"
1112

1213
"github.com/LFDT-Panurus/panurus/token/services/logging"
14+
"github.com/hyperledger-labs/fabric-smart-client/pkg/utils/errors"
1315
"github.com/hyperledger-labs/fabric-smart-client/platform/fabric"
1416
)
1517

18+
const (
19+
// defaultLedgerInfoAttempts is how many times ScanBlock asks the ledger for
20+
// its current height before giving up. A transient RPC hiccup must not
21+
// decide the starting block, so the call is retried rather than trusted once.
22+
defaultLedgerInfoAttempts = 3
23+
// defaultLedgerInfoRetryDelay is the pause before the first retry. It doubles
24+
// on each further attempt, so the defaults span ~1.5s in total.
25+
defaultLedgerInfoRetryDelay = 500 * time.Millisecond
26+
)
27+
28+
// blockFromScanner is the subset of fabric.Delivery used by Delivery: the block
29+
// scan, parameterized by the block to start from.
30+
type blockFromScanner interface {
31+
ScanBlockFrom(ctx context.Context, block uint64, callback fabric.BlockCallback) error
32+
}
33+
34+
// ledgerHeightProvider is the subset of fabric.Ledger used by Delivery: the
35+
// current ledger height, which is where a fresh block scan resumes.
36+
type ledgerHeightProvider interface {
37+
GetLedgerInfo() (*fabric.LedgerInfo, error)
38+
}
39+
1640
type Delivery struct {
17-
*fabric.Delivery
18-
*fabric.Ledger
19-
Logger logging.Logger
41+
Delivery blockFromScanner
42+
Ledger ledgerHeightProvider
43+
Logger logging.Logger
44+
45+
// LedgerInfoAttempts bounds the number of GetLedgerInfo attempts made by
46+
// ScanBlock. Zero or negative selects defaultLedgerInfoAttempts.
47+
LedgerInfoAttempts int
48+
// LedgerInfoRetryDelay is the pause before the first GetLedgerInfo retry; it
49+
// doubles on each further attempt. Zero or negative selects
50+
// defaultLedgerInfoRetryDelay.
51+
LedgerInfoRetryDelay time.Duration
2052
}
2153

54+
// ScanBlock scans blocks starting from the current ledger height.
55+
//
56+
// The height is read from the ledger, retried a bounded number of times so a
57+
// transient RPC failure does not decide where the scan starts. If the height
58+
// remains unavailable, the error is returned instead of falling back to block 0:
59+
// on a chain with history that fallback silently turns a passing RPC hiccup into
60+
// a full rescan from genesis, with duplicate finality notifications and no error
61+
// for the caller to distinguish it from a genuinely fresh chain.
62+
//
63+
// A nil Ledger is the one case that still starts at block 0 — there is no height
64+
// to read, so the whole chain is the intended range.
2265
func (d *Delivery) ScanBlock(background context.Context, callback fabric.BlockCallback) error {
2366
startingBlock := uint64(0)
2467
if d.Ledger != nil {
25-
info, err := d.GetLedgerInfo()
26-
if err == nil {
27-
startingBlock = info.Height
28-
} else {
29-
d.Logger.ErrorfContext(background, "failed to get ledger info: %s", err)
68+
height, err := d.ledgerHeight(background)
69+
if err != nil {
70+
return err
71+
}
72+
startingBlock = height
73+
}
74+
75+
return d.Delivery.ScanBlockFrom(background, startingBlock, callback)
76+
}
77+
78+
// ledgerHeight returns the current ledger height, retrying transient failures
79+
// with an exponentially growing delay. It gives up as soon as the context is
80+
// cancelled, and reports the last observed failure once the attempts run out.
81+
func (d *Delivery) ledgerHeight(ctx context.Context) (uint64, error) {
82+
attempts := d.LedgerInfoAttempts
83+
if attempts <= 0 {
84+
attempts = defaultLedgerInfoAttempts
85+
}
86+
delay := d.LedgerInfoRetryDelay
87+
if delay <= 0 {
88+
delay = defaultLedgerInfoRetryDelay
89+
}
90+
91+
var lastErr error
92+
for attempt := 1; attempt <= attempts; attempt++ {
93+
info, err := d.Ledger.GetLedgerInfo()
94+
switch {
95+
case err != nil:
96+
lastErr = err
97+
case info == nil:
98+
// A driver that reports neither info nor error would otherwise nil
99+
// deref below; treat it as a failure to read the height.
100+
lastErr = errors.New("ledger returned no info")
101+
default:
102+
return info.Height, nil
103+
}
104+
105+
d.Logger.ErrorfContext(ctx, "failed to get ledger info (attempt %d/%d): %s", attempt, attempts, lastErr)
106+
107+
if attempt == attempts {
108+
break
109+
}
110+
111+
select {
112+
case <-ctx.Done():
113+
return 0, errors.Wrapf(ctx.Err(), "cancelled while getting ledger info, last error [%v]", lastErr)
114+
case <-time.After(delay):
30115
}
116+
delay *= 2
31117
}
32118

33-
return d.ScanBlockFrom(background, startingBlock, callback)
119+
return 0, errors.Wrapf(lastErr, "failed to get ledger info after %d attempt(s), refusing to rescan from genesis", attempts)
34120
}
Lines changed: 210 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,210 @@
1+
/*
2+
Copyright IBM Corp. All Rights Reserved.
3+
4+
SPDX-License-Identifier: Apache-2.0
5+
*/
6+
7+
package finality_test
8+
9+
import (
10+
"context"
11+
"errors"
12+
"sync/atomic"
13+
"testing"
14+
"time"
15+
16+
"github.com/LFDT-Panurus/panurus/token/services/logging"
17+
"github.com/LFDT-Panurus/panurus/token/services/network/fabric/finality"
18+
"github.com/hyperledger-labs/fabric-smart-client/platform/fabric"
19+
"github.com/hyperledger/fabric-protos-go-apiv2/common"
20+
"github.com/stretchr/testify/assert"
21+
"github.com/stretchr/testify/require"
22+
)
23+
24+
// heightLedgerResult is one scripted GetLedgerInfo outcome.
25+
type heightLedgerResult struct {
26+
info *fabric.LedgerInfo
27+
err error
28+
}
29+
30+
// fakeHeightLedger returns scripted GetLedgerInfo results, replaying the last
31+
// one once the script is exhausted, and counts how often it was called.
32+
type fakeHeightLedger struct {
33+
results []heightLedgerResult
34+
calls atomic.Int32
35+
}
36+
37+
func (l *fakeHeightLedger) GetLedgerInfo() (*fabric.LedgerInfo, error) {
38+
n := int(l.calls.Add(1))
39+
r := l.results[min(n, len(l.results))-1]
40+
41+
return r.info, r.err
42+
}
43+
44+
// recordingBlockDelivery records the block ScanBlockFrom was asked to start
45+
// from, and whether it was called at all — the observable difference between
46+
// "resumed at the current height", "rescanned from genesis", and "did not scan".
47+
type recordingBlockDelivery struct {
48+
called bool
49+
startingBlock uint64
50+
callback fabric.BlockCallback
51+
err error
52+
}
53+
54+
func (d *recordingBlockDelivery) ScanBlockFrom(_ context.Context, block uint64, callback fabric.BlockCallback) error {
55+
d.called = true
56+
d.startingBlock = block
57+
d.callback = callback
58+
59+
return d.err
60+
}
61+
62+
// newTestDelivery builds a Delivery over the two fakes, with a retry delay short
63+
// enough to keep the tests fast.
64+
func newTestDelivery(l *fakeHeightLedger, d *recordingBlockDelivery) *finality.Delivery {
65+
return &finality.Delivery{
66+
Delivery: d,
67+
Ledger: l,
68+
Logger: logging.MustGetLogger(),
69+
LedgerInfoRetryDelay: time.Millisecond,
70+
}
71+
}
72+
73+
// TestScanBlock_StartsFromCurrentLedgerHeight covers the happy path: the scan
74+
// resumes at the height reported by the ledger, with the caller's callback
75+
// passed through untouched.
76+
func TestScanBlock_StartsFromCurrentLedgerHeight(t *testing.T) {
77+
ledger := &fakeHeightLedger{results: []heightLedgerResult{{info: &fabric.LedgerInfo{Height: 42}}}}
78+
delivery := &recordingBlockDelivery{}
79+
80+
callbackInvoked := false
81+
callback := func(context.Context, *common.Block) (bool, error) {
82+
callbackInvoked = true
83+
84+
return false, nil
85+
}
86+
87+
require.NoError(t, newTestDelivery(ledger, delivery).ScanBlock(context.Background(), callback))
88+
89+
assert.True(t, delivery.called)
90+
assert.Equal(t, uint64(42), delivery.startingBlock)
91+
assert.Equal(t, int32(1), ledger.calls.Load(), "a successful GetLedgerInfo must not be retried")
92+
93+
require.NotNil(t, delivery.callback)
94+
_, err := delivery.callback(context.Background(), nil)
95+
require.NoError(t, err)
96+
assert.True(t, callbackInvoked, "the caller's callback must be the one handed to ScanBlockFrom")
97+
}
98+
99+
// TestScanBlock_PropagatesLedgerInfoErrorInsteadOfRescanningFromGenesis is the
100+
// regression test for issue #2058: a persistent GetLedgerInfo failure used to be
101+
// logged and swallowed, leaving startingBlock at 0 and silently triggering a full
102+
// rescan from genesis. The error must now reach the caller, and no scan must start.
103+
func TestScanBlock_PropagatesLedgerInfoErrorInsteadOfRescanningFromGenesis(t *testing.T) {
104+
transient := errors.New("peer connection reset")
105+
ledger := &fakeHeightLedger{results: []heightLedgerResult{{err: transient}}}
106+
delivery := &recordingBlockDelivery{}
107+
108+
err := newTestDelivery(ledger, delivery).ScanBlock(context.Background(), nil)
109+
110+
require.Error(t, err, "GetLedgerInfo failure must be propagated, not swallowed after a log line")
111+
require.ErrorIs(t, err, transient, "the underlying ledger error must stay inspectable")
112+
assert.Contains(t, err.Error(), "refusing to rescan from genesis")
113+
assert.False(t, delivery.called, "no scan may start from genesis when the ledger height is unknown")
114+
}
115+
116+
// TestScanBlock_RetriesTransientLedgerInfoFailure verifies the transient case the
117+
// issue describes — an ordinary RPC hiccup — is absorbed by a retry and resumes at
118+
// the real height, rather than either failing or rescanning from block 0.
119+
func TestScanBlock_RetriesTransientLedgerInfoFailure(t *testing.T) {
120+
ledger := &fakeHeightLedger{results: []heightLedgerResult{
121+
{err: errors.New("peer connection reset")},
122+
{info: &fabric.LedgerInfo{Height: 7}},
123+
}}
124+
delivery := &recordingBlockDelivery{}
125+
126+
require.NoError(t, newTestDelivery(ledger, delivery).ScanBlock(context.Background(), nil))
127+
128+
assert.Equal(t, int32(2), ledger.calls.Load())
129+
assert.True(t, delivery.called)
130+
assert.Equal(t, uint64(7), delivery.startingBlock, "must resume at the height read on the retry, not at genesis")
131+
}
132+
133+
// TestScanBlock_RetriesAreBounded verifies the retry loop honours the configured
134+
// attempt budget instead of spinning on a permanently failing ledger.
135+
func TestScanBlock_RetriesAreBounded(t *testing.T) {
136+
ledger := &fakeHeightLedger{results: []heightLedgerResult{{err: errors.New("peer connection reset")}}}
137+
delivery := &recordingBlockDelivery{}
138+
139+
d := newTestDelivery(ledger, delivery)
140+
d.LedgerInfoAttempts = 5
141+
142+
require.Error(t, d.ScanBlock(context.Background(), nil))
143+
assert.Equal(t, int32(5), ledger.calls.Load())
144+
assert.False(t, delivery.called)
145+
}
146+
147+
// TestScanBlock_NilLedgerInfoIsReportedNotDereferenced covers a driver that
148+
// reports neither info nor error: that used to be a nil dereference waiting on
149+
// info.Height, and must instead surface as an error.
150+
func TestScanBlock_NilLedgerInfoIsReportedNotDereferenced(t *testing.T) {
151+
ledger := &fakeHeightLedger{results: []heightLedgerResult{{}}}
152+
delivery := &recordingBlockDelivery{}
153+
154+
err := newTestDelivery(ledger, delivery).ScanBlock(context.Background(), nil)
155+
156+
require.Error(t, err)
157+
assert.Contains(t, err.Error(), "ledger returned no info")
158+
assert.False(t, delivery.called)
159+
}
160+
161+
// TestScanBlock_CancelledContextStopsRetrying verifies shutdown does not have to
162+
// wait out the retry budget: a cancelled context ends the loop with its own error.
163+
func TestScanBlock_CancelledContextStopsRetrying(t *testing.T) {
164+
ledger := &fakeHeightLedger{results: []heightLedgerResult{{err: errors.New("peer connection reset")}}}
165+
delivery := &recordingBlockDelivery{}
166+
167+
d := newTestDelivery(ledger, delivery)
168+
d.LedgerInfoAttempts = 100
169+
d.LedgerInfoRetryDelay = time.Hour // only cancellation can end this loop in time
170+
171+
ctx, cancel := context.WithCancel(context.Background())
172+
cancel()
173+
174+
done := make(chan error, 1)
175+
go func() { done <- d.ScanBlock(ctx, nil) }()
176+
177+
select {
178+
case err := <-done:
179+
require.ErrorIs(t, err, context.Canceled)
180+
assert.Equal(t, int32(1), ledger.calls.Load(), "must not keep retrying after cancellation")
181+
assert.False(t, delivery.called)
182+
case <-time.After(10 * time.Second):
183+
t.Fatal("ScanBlock kept retrying after its context was cancelled")
184+
}
185+
}
186+
187+
// TestScanBlock_NilLedgerScansFromGenesis pins the one remaining path that
188+
// legitimately starts at block 0: no ledger is configured, so there is no height
189+
// to resume from and the whole chain is the intended range.
190+
func TestScanBlock_NilLedgerScansFromGenesis(t *testing.T) {
191+
delivery := &recordingBlockDelivery{}
192+
d := &finality.Delivery{Delivery: delivery, Logger: logging.MustGetLogger()}
193+
194+
require.NoError(t, d.ScanBlock(context.Background(), nil))
195+
assert.True(t, delivery.called)
196+
assert.Equal(t, uint64(0), delivery.startingBlock)
197+
}
198+
199+
// TestScanBlock_PropagatesScanError verifies the scan's own error is returned
200+
// unchanged once the starting block has been resolved.
201+
func TestScanBlock_PropagatesScanError(t *testing.T) {
202+
scanErr := errors.New("delivery stream broken")
203+
ledger := &fakeHeightLedger{results: []heightLedgerResult{{info: &fabric.LedgerInfo{Height: 3}}}}
204+
delivery := &recordingBlockDelivery{err: scanErr}
205+
206+
err := newTestDelivery(ledger, delivery).ScanBlock(context.Background(), nil)
207+
208+
require.ErrorIs(t, err, scanErr)
209+
assert.Equal(t, uint64(3), delivery.startingBlock)
210+
}

0 commit comments

Comments
 (0)