Skip to content

Commit 6a84380

Browse files
xlcxlc
authored
fix block author (#185)
* fix block author * update * test refactor and fix * update * mark some scheduler test intermittent * update * add unique id to logger label * improve tests * fix
1 parent 1fd9381 commit 6a84380

22 files changed

+340
-223
lines changed

‎Blockchain/Sources/Blockchain/Blockchain.swift‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -15,7 +15,7 @@ public final class Blockchain: ServiceBase, @unchecked Sendable {
1515
self.dataProvider = dataProvider
1616
self.timeProvider = timeProvider
1717

18-
super.init(logger: Logger(label: "Blockchain"), config: config, eventBus: eventBus)
18+
super.init(id: "Blockchain", config: config, eventBus: eventBus)
1919

2020
await subscribe(RuntimeEvents.BlockAuthored.self, id: "Blockchain.BlockAuthored") { [weak self] event in
2121
try await self?.on(blockAuthored: event)

‎Blockchain/Sources/Blockchain/RuntimeProtocols/Runtime.swift‎

Lines changed: 17 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,10 @@
11
import Codec
22
import Foundation
3+
import TracingUtils
34
import Utils
45

6+
private let logger = Logger(label: "Runtime")
7+
58
// the STF
69
public final class Runtime {
710
public enum Error: Swift.Error {
@@ -22,7 +25,8 @@ public final class Runtime {
2225
case preimagesNotSorted
2326
case invalidPreimageServiceIndex
2427
case duplicatedPreimage
25-
case notBlockAuthor
28+
case invalidAuthorTicket
29+
case invalidAuthorKey
2630
case invalidBlockSeal(any Swift.Error)
2731
case invalidVrfSignature
2832
case other(any Swift.Error)
@@ -70,19 +74,20 @@ public final class Runtime {
7074
// winning tickets is validated at apply time by Safrole
7175

7276
// offendersMarkers is validated at apply time by Disputes
77+
}
7378

74-
// validate block.header.seal
79+
public func validateHeaderSeal(block: BlockRef, state: inout State) throws(Error) {
7580
let vrfOutput: Data32
7681
let blockAuthorKey = try Result {
77-
try Bandersnatch.PublicKey(data: state.value.currentValidators[Int(block.header.authorIndex)].bandersnatch)
82+
try Bandersnatch.PublicKey(data: state.currentValidators[Int(block.header.authorIndex)].bandersnatch)
7883
}.mapError(Error.invalidBlockSeal).get()
7984
let index = block.header.timeslot % UInt32(config.value.epochLength)
8085
let encodedHeader = try Result { try JamEncoder.encode(block.header.unsigned) }.mapError(Error.invalidBlockSeal).get()
8186
let entropyVRFInputData: Data
82-
switch state.value.safroleState.ticketsOrKeys {
87+
switch state.safroleState.ticketsOrKeys {
8388
case let .left(tickets):
8489
let ticket = tickets[Int(index)]
85-
let vrfInputData = SigningContext.safroleTicketInputData(entropy: state.value.entropyPool.t3, attempt: ticket.attempt)
90+
let vrfInputData = SigningContext.safroleTicketInputData(entropy: state.entropyPool.t3, attempt: ticket.attempt)
8691
vrfOutput = try Result {
8792
try blockAuthorKey.ietfVRFVerify(
8893
vrfInputData: vrfInputData,
@@ -91,17 +96,18 @@ public final class Runtime {
9196
)
9297
}.mapError(Error.invalidBlockSeal).get()
9398
guard ticket.id == vrfOutput else {
94-
throw Error.notBlockAuthor
99+
throw Error.invalidAuthorTicket
95100
}
96101

97102
entropyVRFInputData = SigningContext.entropyInputData(entropy: vrfOutput)
98103

99104
case let .right(keys):
100105
let key = keys[Int(index)]
101106
guard key == blockAuthorKey.data else {
102-
throw Error.notBlockAuthor
107+
logger.debug("expected key: \(key.toHexString()), got key: \(blockAuthorKey.data.toHexString())")
108+
throw Error.invalidAuthorKey
103109
}
104-
let vrfInputData = SigningContext.fallbackSealInputData(entropy: state.value.entropyPool.t3)
110+
let vrfInputData = SigningContext.fallbackSealInputData(entropy: state.entropyPool.t3)
105111
vrfOutput = try Result {
106112
try blockAuthorKey.ietfVRFVerify(
107113
vrfInputData: vrfInputData,
@@ -110,7 +116,7 @@ public final class Runtime {
110116
)
111117
}.mapError(Error.invalidBlockSeal).get()
112118

113-
entropyVRFInputData = SigningContext.fallbackSealInputData(entropy: state.value.entropyPool.t3)
119+
entropyVRFInputData = SigningContext.fallbackSealInputData(entropy: state.entropyPool.t3)
114120
}
115121

116122
_ = try Result {
@@ -150,6 +156,8 @@ public final class Runtime {
150156
do {
151157
try updateSafrole(block: block, state: &newState)
152158

159+
try validateHeaderSeal(block: block, state: &newState)
160+
153161
try updateDisputes(block: block, state: &newState)
154162

155163
// depends on Safrole and Disputes

‎Blockchain/Sources/Blockchain/Types/StateRef.swift‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -22,6 +22,10 @@ public final class StateRef: Ref<State>, @unchecked Sendable {
2222
public var stateRoot: Data32 {
2323
lazyStateRoot.value.value
2424
}
25+
26+
override public var description: String {
27+
"StateRef(\(stateRoot.toHexString()))"
28+
}
2529
}
2630

2731
extension StateRef: Codable {

‎Blockchain/Sources/Blockchain/Validator/BlockAuthor.swift‎

Lines changed: 14 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,6 @@
11
import Codec
22
import Foundation
3+
import Synchronization
34
import TracingUtils
45
import Utils
56

@@ -8,7 +9,7 @@ public final class BlockAuthor: ServiceBase2, @unchecked Sendable {
89
private let keystore: KeyStore
910
private let extrinsicPool: ExtrinsicPoolService
1011

11-
private var tickets: ThreadSafeContainer<[RuntimeEvents.SafroleTicketsGenerated]> = .init([])
12+
private let tickets: ThreadSafeContainer<[RuntimeEvents.SafroleTicketsGenerated]> = .init([])
1213

1314
public init(
1415
config: ProtocolConfigRef,
@@ -22,7 +23,7 @@ public final class BlockAuthor: ServiceBase2, @unchecked Sendable {
2223
self.keystore = keystore
2324
self.extrinsicPool = extrinsicPool
2425

25-
super.init(logger: Logger(label: "BlockAuthor"), config: config, eventBus: eventBus, scheduler: scheduler)
26+
super.init(id: "BlockAuthor", config: config, eventBus: eventBus, scheduler: scheduler)
2627

2728
await subscribe(RuntimeEvents.SafroleTicketsGenerated.self, id: "BlockAuthor.SafroleTicketsGenerated") { [weak self] event in
2829
try await self?.on(safroleTicketsGenerated: event)
@@ -33,11 +34,11 @@ public final class BlockAuthor: ServiceBase2, @unchecked Sendable {
3334
}
3435
}
3536

36-
public func on(genesis state: StateRef) async {
37-
await scheduleNewBlocks(
38-
ticketsOrKeys: state.value.safroleState.ticketsOrKeys,
39-
timeslot: timeProvider.getTime().timeToTimeslot(config: config)
40-
)
37+
public func on(genesis _: StateRef) async {
38+
let nowTimeslot = timeProvider.getTime().timeToTimeslot(config: config)
39+
// schedule for current epoch
40+
let epoch = (nowTimeslot + 1).timeslotToEpochIndex(config: config)
41+
await onBeforeEpoch(epoch: epoch)
4142
}
4243

4344
public func createNewBlock(
@@ -47,6 +48,9 @@ public final class BlockAuthor: ServiceBase2, @unchecked Sendable {
4748
-> BlockRef
4849
{
4950
let parentHash = dataProvider.bestHead
51+
52+
logger.trace("creating new block for timeslot: \(timeslot) with parent hash: \(parentHash)")
53+
5054
let state = try await dataProvider.getState(hash: parentHash)
5155
let epoch = timeslot.timeslotToEpochIndex(config: config)
5256

@@ -156,7 +160,7 @@ public final class BlockAuthor: ServiceBase2, @unchecked Sendable {
156160
await withSpan("BlockAuthor.newBlock", logger: logger) { _ in
157161
// TODO: add timeout
158162
let block = try await createNewBlock(timeslot: timeslot, claim: claim)
159-
logger.info("New block created: #\(block.header.timeslot) \(block.hash)")
163+
logger.info("New block created: #\(block.header.timeslot) \(block.hash) on parent #\(block.header.parentHash)")
160164
publish(RuntimeEvents.BlockAuthored(block: block))
161165
}
162166
}
@@ -205,7 +209,7 @@ public final class BlockAuthor: ServiceBase2, @unchecked Sendable {
205209
if delay < 0 {
206210
continue
207211
}
208-
logger.debug("Scheduling new block task at timeslot \(timeslot)")
212+
logger.trace("Scheduling new block task at timeslot \(timeslot) for claim \(claim.1.data.toHexString())")
209213
schedule(id: "BlockAuthor.newBlock", delay: delay) { [weak self] in
210214
if let self {
211215
await newBlock(timeslot: timeslot, claim: .left(claim))
@@ -223,7 +227,7 @@ public final class BlockAuthor: ServiceBase2, @unchecked Sendable {
223227
if delay < 0 {
224228
continue
225229
}
226-
logger.debug("Scheduling new block task at timeslot \(timeslot)")
230+
logger.trace("Scheduling new block task at timeslot \(timeslot) for key \(pubkey.data.toHexString())")
227231
schedule(id: "BlockAuthor.newBlock", delay: delay) { [weak self] in
228232
if let self {
229233
await newBlock(timeslot: timeslot, claim: .right(pubkey))

‎Blockchain/Sources/Blockchain/Validator/ExtrinsicPoolService.swift‎

Lines changed: 10 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -4,7 +4,7 @@ import Utils
44
private typealias TicketItem = ExtrinsicTickets.TicketItem
55

66
private actor ServiceStorage {
7-
let logger: Logger
7+
var logger: Logger!
88

99
// sorted array ordered by output
1010
var pendingTickets: SortedUniqueArray<TicketItemAndOutput> = .init()
@@ -13,11 +13,14 @@ private actor ServiceStorage {
1313
var entropy: Data32 = .init()
1414
let ringContext: Bandersnatch.RingContext
1515

16-
init(logger: Logger, ringContext: Bandersnatch.RingContext) {
17-
self.logger = logger
16+
init(ringContext: Bandersnatch.RingContext) {
1817
self.ringContext = ringContext
1918
}
2019

20+
func setLogger(_ logger: Logger) {
21+
self.logger = logger
22+
}
23+
2124
func add(tickets: [TicketItem], config: ProtocolConfigRef) {
2225
for ticket in tickets {
2326
if (try? ticket.validate(config: config)) == nil {
@@ -77,12 +80,12 @@ public final class ExtrinsicPoolService: ServiceBase, @unchecked Sendable {
7780
) async {
7881
self.dataProvider = dataProvider
7982

80-
let logger = Logger(label: "ExtrinsicPoolService")
81-
8283
let ringContext = try! Bandersnatch.RingContext(size: UInt(config.value.totalNumberOfValidators))
83-
storage = ServiceStorage(logger: logger, ringContext: ringContext)
84+
storage = ServiceStorage(ringContext: ringContext)
85+
86+
super.init(id: "ExtrinsicPoolService", config: config, eventBus: eventBus)
8487

85-
super.init(logger: logger, config: config, eventBus: eventBus)
88+
await storage.setLogger(logger)
8689

8790
await subscribe(RuntimeEvents.SafroleTicketsGenerated.self, id: "ExtrinsicPool.SafroleTicketsGenerated") { [weak self] event in
8891
try await self?.on(safroleTicketsGenerated: event)

‎Blockchain/Sources/Blockchain/Validator/GuaranteeingService.swift‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -28,7 +28,7 @@ public final class GuaranteeingService: ServiceBase2, @unchecked Sendable {
2828
self.runtime = runtime
2929
self.extrinsicPool = extrinsicPool
3030

31-
super.init(logger: Logger(label: "BlockAuthor"), config: config, eventBus: eventBus, scheduler: scheduler)
31+
super.init(id: "BlockAuthor", config: config, eventBus: eventBus, scheduler: scheduler)
3232
}
3333

3434
public func on(genesis _: StateRef) async {}

‎Blockchain/Sources/Blockchain/Validator/SafroleService.swift‎

Lines changed: 2 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -27,7 +27,7 @@ public final class SafroleService: ServiceBase, @unchecked Sendable {
2727
self.keystore = keystore
2828
ringContext = try! Bandersnatch.RingContext(size: UInt(config.value.totalNumberOfValidators))
2929

30-
super.init(logger: Logger(label: "SafroleService"), config: config, eventBus: eventBus)
30+
super.init(id: "SafroleService", config: config, eventBus: eventBus)
3131

3232
await subscribe(RuntimeEvents.BlockImported.self, id: "SafroleService.BlockImported") { [weak self] event in
3333
try await self?.on(blockImported: event)
@@ -66,8 +66,6 @@ public final class SafroleService: ServiceBase, @unchecked Sendable {
6666
continue
6767
}
6868

69-
logger.debug("Generating tickets for validator \(pubkey)")
70-
7169
try withSpan("generateTickets") { _ in
7270
let tickets = try SafroleService.generateTickets(
7371
count: TicketIndex(config.value.ticketEntriesPerValidator),
@@ -86,7 +84,7 @@ public final class SafroleService: ServiceBase, @unchecked Sendable {
8684
}
8785

8886
if events.isEmpty {
89-
logger.debug("Not in next validators")
87+
logger.trace("Not in next validators")
9088
}
9189

9290
return events

‎Blockchain/Sources/Blockchain/Validator/ServiceBase.swift‎

Lines changed: 5 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -2,13 +2,15 @@ import TracingUtils
22
import Utils
33

44
public class ServiceBase {
5-
public let logger: Logger
5+
public let id: UniqueId
6+
let logger: Logger
67
public let config: ProtocolConfigRef
78
private let eventBus: EventBus
89
private let subscriptionTokens: ThreadSafeContainer<[EventBus.SubscriptionToken]> = .init([])
910

10-
init(logger: Logger, config: ProtocolConfigRef, eventBus: EventBus) {
11-
self.logger = logger
11+
init(id: UniqueId, config: ProtocolConfigRef, eventBus: EventBus) {
12+
self.id = id
13+
logger = Logger(label: id)
1214
self.config = config
1315
self.eventBus = eventBus
1416
}

‎Blockchain/Sources/Blockchain/Validator/ServiceBase2.swift‎

Lines changed: 7 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -20,9 +20,9 @@ public class ServiceBase2: ServiceBase, @unchecked Sendable {
2020
private let scheduler: Scheduler
2121
private let cancellables: ThreadSafeContainer<Set<IdCancellable>> = .init([])
2222

23-
public init(logger: Logger, config: ProtocolConfigRef, eventBus: EventBus, scheduler: Scheduler) {
23+
public init(id: UniqueId, config: ProtocolConfigRef, eventBus: EventBus, scheduler: Scheduler) {
2424
self.scheduler = scheduler
25-
super.init(logger: logger, config: config, eventBus: eventBus)
25+
super.init(id: id, config: config, eventBus: eventBus)
2626
}
2727

2828
deinit {
@@ -63,8 +63,8 @@ public class ServiceBase2: ServiceBase, @unchecked Sendable {
6363

6464
@discardableResult
6565
public func scheduleForNextEpoch(_ id: UniqueId, fn: @escaping @Sendable (EpochIndex) async -> Void) -> Cancellable {
66-
let now = timeProvider.getTimeInterval()
67-
let nowTimeslot = UInt32(now).timeToTimeslot(config: config)
66+
let now = timeProvider.getTime()
67+
let nowTimeslot = now.timeToTimeslot(config: config)
6868
let nextEpoch = (nowTimeslot + 1).timeslotToEpochIndex(config: config) + 1
6969
return scheduleFor(epoch: nextEpoch, id: id, fn: fn)
7070
}
@@ -73,12 +73,10 @@ public class ServiceBase2: ServiceBase, @unchecked Sendable {
7373
private func scheduleFor(epoch: EpochIndex, id: UniqueId, fn: @escaping @Sendable (EpochIndex) async -> Void) -> Cancellable {
7474
let scheduleTime = config.scheduleTimeForPrepareEpoch(epoch: epoch)
7575
let now = timeProvider.getTimeInterval()
76-
let delay = scheduleTime - now
76+
var delay = scheduleTime - now
7777
if delay < 0 {
78-
// too late / current epoch is about to end
79-
// schedule for the one after
80-
logger.debug("\(id): skipping epoch \(epoch) because it is too late")
81-
return scheduleFor(epoch: epoch + 1, id: id, fn: fn)
78+
logger.debug("\(id): late epoch start \(epoch), expectedDelay \(delay)")
79+
delay = 0
8280
}
8381
logger.trace("\(id): scheduling epoch \(epoch) in \(delay)")
8482
return schedule(id: id, delay: delay) { [weak self] in

0 commit comments

Comments
 (0)