Skip to content
This repository has been archived by the owner on Jun 11, 2024. It is now read-only.

Commit

Permalink
♻️ Handle error at new block subscribe
Browse files Browse the repository at this point in the history
  • Loading branch information
@ishantiw
ishantiw committed Mar 13, 2024
1 parent 228050a commit 053a4e0
Show file tree
Hide file tree
Showing 4 changed files with 93 additions and 90 deletions.
109 changes: 56 additions & 53 deletions framework-plugins/lisk-framework-chain-connector-plugin/src/block_event_handler.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -113,12 +113,24 @@ export class BlockEventHandler {
// On a new block start with CCU creation process
this._sendingChainAPIClient.subscribe(
'chain_newBlock',
async (data?: Record<string, unknown>) => this._handleNewBlock(data),
async (data?: Record<string, unknown>) => {
try {
await this._handleNewBlock(data);
} catch (error) {
this._logger.error({ err: error as Error }, 'Failed to handle new block.');
}
},
);

this._sendingChainAPIClient.subscribe(
'chain_deleteBlock',
async (data?: Record<string, unknown>) => this._deleteBlockHandler(data),
async (data?: Record<string, unknown>) => {
try {
await this._deleteBlockHandler(data);
} catch (error) {
this._logger.error({ err: error as Error }, 'Failed to handle delete block.');
}
},
);

// Initialize the receiving chain client in the end of load so not to miss the initial new blocks
Expand All @@ -129,12 +141,8 @@ export class BlockEventHandler {
const { blockHeader: receivedBlock } = data as unknown as Data;
const newBlockHeader = chain.BlockHeader.fromJSON(receivedBlock).toObject();

try {
await this._saveOnNewBlock(newBlockHeader);
} catch (error) {
this._logger.error({ err: error as Error }, 'Error occurred while saving data on new block.');
return;
}
await this._saveOnNewBlock(newBlockHeader);

const nodeInfo = await this._sendingChainAPIClient.getNodeInfo();

if (nodeInfo.syncing) {
Expand All @@ -148,6 +156,7 @@ export class BlockEventHandler {
chainAccount = await this._receivingChainAPIClient.getChainAccount(this._ownChainID);
} catch (error) {
// If receivingChainAPIClient is not ready then still save data on new block
// Error is handled within this function so need to have try/catch
await this._initializeReceivingChainClient();
this._logger.error(
{ err: error as Error },
Expand All @@ -166,13 +175,13 @@ export class BlockEventHandler {
}

this._lastCertificate = chainAccount.lastCertificate;
this._logger.debug(
this._logger.info(
`Last certificate value has been set with height ${this._lastCertificate.height}`,
);

const numOfBlocksSinceLastCertificate = newBlockHeader.height - this._lastCertificate.height;
if (this._ccuFrequency > numOfBlocksSinceLastCertificate) {
this._logger.debug(
this._logger.info(
{
ccuFrequency: this._ccuFrequency,
nextPossibleCCUHeight: this._ccuFrequency - numOfBlocksSinceLastCertificate,
Expand All @@ -196,59 +205,53 @@ export class BlockEventHandler {
}
this._isReceivingChainRegistered = true;
}

let computedCCUParams;
try {
// Compute CCU when there is no pending CCU that was sent earlier
if (this._lastSentCCUTxID === '') {
computedCCUParams = await this._ccuHandler.computeCCU(
this._lastCertificate,
this._lastIncludedCCMOnReceivingChain,
);
} else {
this._logger.info(
`Still pending CCU on the receiving CCU with tx ID ${this._lastSentCCUTxID}`,
);

return;
}
} catch (error) {
this._logger.error(
{ err: error },
`Error occurred while computing CCU for the blockHeader at height: ${newBlockHeader.height}`,
// Compute CCU when there is no pending CCU that was sent earlier
if (this._lastSentCCUTxID === '') {
computedCCUParams = await this._ccuHandler.computeCCU(
this._lastCertificate,
this._lastIncludedCCMOnReceivingChain,
);
} else {
this._logger.info(
`Still pending CCU on the receiving CCU with tx ID ${this._lastSentCCUTxID}`,
);

return;
}

if (computedCCUParams) {
try {
const ccuSubmitResult = await this._ccuHandler.submitCCU(
computedCCUParams.ccuParams,
this._lastSentCCUTxID,
);
if (ccuSubmitResult) {
this._lastSentCCUTxID = ccuSubmitResult;
// Wait until 1 hour
this._sentCCUTxTimeout = setTimeout(() => {
this._lastSentCCUTxID = '';
clearTimeout(this._sentCCUTxTimeout);
}, DEFAULT_SENT_CCU_TIMEOUT);
// If CCU was sent successfully then save the lastSentCCM if any
if (computedCCUParams.lastCCMToBeSent) {
this._lastSentCCM = computedCCUParams.lastCCMToBeSent;
}
return;
}
this._logger.debug(
`Last sent CCU tx with ID ${this._lastSentCCUTxID} was not yet included in the receiving chain.`,
);
} catch (error) {
this._logger.error(
{ err: error },
`Error occured while submitting CCU for the blockHeader at height: ${newBlockHeader.height}`,
if (!computedCCUParams) {
this._logger.info(`No CCU params were generated for block height ${newBlockHeader.height}`);

return;
}

const ccuSubmitResult = await this._ccuHandler.submitCCU(
computedCCUParams.ccuParams,
this._lastSentCCUTxID,
);
if (ccuSubmitResult) {
this._lastSentCCUTxID = ccuSubmitResult;
// Wait until 1 hour
this._sentCCUTxTimeout = setTimeout(() => {
this._lastSentCCUTxID = '';
clearTimeout(this._sentCCUTxTimeout);
}, DEFAULT_SENT_CCU_TIMEOUT);
// If CCU was sent successfully then save the lastSentCCM if any
if (computedCCUParams.lastCCMToBeSent) {
this._lastSentCCM = computedCCUParams.lastCCMToBeSent;
this._logger.info(
`Last sent CCM with nonce ${this._lastSentCCM.nonce.toString()} is saved.`,
);
}
this._logger.info(`CCU transaction was successfully sent with Tx ID ${ccuSubmitResult}.`);
return;
}
this._logger.info(
`Last sent CCU tx with ID ${this._lastSentCCUTxID} was not yet included in the receiving chain.`,
);
}

private async _saveOnNewBlock(newBlockHeader: BlockHeader) {
Expand Down
2 changes: 0 additions & 2 deletions framework-plugins/lisk-framework-chain-connector-plugin/src/ccu_handler.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -319,8 +319,6 @@ export class CCUHandler {
}
// Save the sent CCU
await this._db.setCCUTransaction(tx.toObject());
// Update logs
this._logger.info({ transactionID: result.transactionId }, 'Sent CCU transaction');

return result.transactionId;
}
Expand Down
68 changes: 37 additions & 31 deletions ...ework-plugins/lisk-framework-chain-connector-plugin/test/unit/block_event_handler.spec.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -225,17 +225,14 @@ describe('BlockEventHandler', () => {
clearTimeout(blockEventHandler['_sentCCUTxTimeout']);
});

it('should log error and return when _saveOnNewBlock fails', async () => {
it('should throw when _saveOnNewBlock fails', async () => {
const fakeError = new Error('Error occurred while save on new block');
saveOnNewBlockMock.mockRejectedValue(fakeError);
jest.spyOn(initArgs.logger as Logger, 'error');

await blockEventHandler['_handleNewBlock']({ blockHeader: sampleBlockHeader });

expect((initArgs.logger as Logger).error).toHaveBeenCalledWith(
{ err: fakeError },
'Error occurred while saving data on new block.',
);
await expect(
blockEventHandler['_handleNewBlock']({ blockHeader: sampleBlockHeader }),
).rejects.toThrow(fakeError);
});

it('should return after getNodeInfo when the node is syncing', async () => {
Expand Down Expand Up @@ -283,14 +280,14 @@ describe('BlockEventHandler', () => {
saveOnNewBlockMock.mockResolvedValue({});
receivingChainAPIClientMock.getChainAccount.mockResolvedValue(sidechainChainAccount);
sendingChainAPIClientMock.getNodeInfo.mockResolvedValue({ syncing: false });
jest.spyOn(initArgs.logger as Logger, 'debug');
jest.spyOn(initArgs.logger as Logger, 'info');
(blockEventHandler as any)['_ccuFrequency'] = 100;

await blockEventHandler['_handleNewBlock']({ blockHeader: sampleBlockHeader });
expect((initArgs.logger as Logger).debug).toHaveBeenCalledWith(
expect((initArgs.logger as Logger).info).toHaveBeenCalledWith(
`Last certificate value has been set with height ${sidechainLastCertificate.height}`,
);
expect((initArgs.logger as Logger).debug).toHaveBeenCalledWith(
expect((initArgs.logger as Logger).info).toHaveBeenCalledWith(
{
ccuFrequency: 100,
nextPossibleCCUHeight:
Expand All @@ -300,6 +297,19 @@ describe('BlockEventHandler', () => {
);
});

it('should throw error when getChainAccount fails on sending chain client', async () => {
const fakeError = new Error('Failed to get chain account');
saveOnNewBlockMock.mockResolvedValue({});
receivingChainAPIClientMock.getChainAccount.mockResolvedValue(sidechainChainAccount);
sendingChainAPIClientMock.getNodeInfo.mockResolvedValue({ syncing: false });
sendingChainAPIClientMock.getChainAccount.mockRejectedValue(fakeError);
jest.spyOn(initArgs.logger as Logger, 'error');

await expect(
blockEventHandler['_handleNewBlock']({ blockHeader: sampleBlockHeader }),
).rejects.toThrow(fakeError);
});

it('should log message and return when receiving chain is not registered yet', async () => {
saveOnNewBlockMock.mockResolvedValue({});
receivingChainAPIClientMock.getChainAccount.mockResolvedValue(sidechainChainAccount);
Expand Down Expand Up @@ -340,15 +350,11 @@ describe('BlockEventHandler', () => {
blockEventHandler['_isReceivingChainRegistered'] = true;
blockEventHandler['_lastSentCCUTxID'] = lastSentCCUTxID;

await blockEventHandler['_handleNewBlock']({ blockHeader: sampleBlockHeader });

expect((initArgs.logger as Logger).error).toHaveBeenCalledWith(
{ err: fakeError },
`Error occurred while computing CCU for the blockHeader at height: ${
sampleBlockHeader.height as number
}`,
);
await expect(
blockEventHandler['_handleNewBlock']({ blockHeader: sampleBlockHeader }),
).rejects.toThrow(fakeError);
});

it('should log error when submitCCU fails', async () => {
const lastSentCCUTxID = '';
const fakeError = new Error('Failed at computeCCU');
Expand All @@ -365,21 +371,17 @@ describe('BlockEventHandler', () => {
blockEventHandler['_isReceivingChainRegistered'] = true;
blockEventHandler['_lastSentCCUTxID'] = lastSentCCUTxID;

await blockEventHandler['_handleNewBlock']({ blockHeader: sampleBlockHeader });

expect((initArgs.logger as Logger).error).toHaveBeenCalledWith(
{ err: fakeError },
`Error occured while submitting CCU for the blockHeader at height: ${
sampleBlockHeader.height as number
}`,
);
await expect(
blockEventHandler['_handleNewBlock']({ blockHeader: sampleBlockHeader }),
).rejects.toThrow(fakeError);
});

it('should log message when submitCCU returns undefined', async () => {
const lastSentCCUTxID = '';
saveOnNewBlockMock.mockResolvedValue({});
receivingChainAPIClientMock.getChainAccount.mockResolvedValue(sidechainChainAccount);
sendingChainAPIClientMock.getNodeInfo.mockResolvedValue({ syncing: false });
jest.spyOn(initArgs.logger as Logger, 'debug');
jest.spyOn(initArgs.logger as Logger, 'info');
jest.spyOn(blockEventHandler['_ccuHandler'], 'computeCCU').mockResolvedValue({
ccuParams: {} as any,
lastCCMToBeSent: {} as any,
Expand All @@ -391,7 +393,7 @@ describe('BlockEventHandler', () => {

await blockEventHandler['_handleNewBlock']({ blockHeader: sampleBlockHeader });

expect((initArgs.logger as Logger).debug).toHaveBeenCalledWith(
expect((initArgs.logger as Logger).info).toHaveBeenCalledWith(
`Last sent CCU tx with ID ${lastSentCCUTxID} was not yet included in the receiving chain.`,
);
});
Expand All @@ -401,10 +403,12 @@ describe('BlockEventHandler', () => {
saveOnNewBlockMock.mockResolvedValue({});
receivingChainAPIClientMock.getChainAccount.mockResolvedValue(sidechainChainAccount);
sendingChainAPIClientMock.getNodeInfo.mockResolvedValue({ syncing: false });
jest.spyOn(initArgs.logger as Logger, 'debug');
jest.spyOn(initArgs.logger as Logger, 'info');
jest.spyOn(blockEventHandler['_ccuHandler'], 'computeCCU').mockResolvedValue({
ccuParams: {} as any,
lastCCMToBeSent: {} as any,
lastCCMToBeSent: {
nonce: BigInt(1),
} as any,
});
jest.spyOn(blockEventHandler['_ccuHandler'], 'submitCCU').mockResolvedValue('txID');

Expand All @@ -413,7 +417,9 @@ describe('BlockEventHandler', () => {

await blockEventHandler['_handleNewBlock']({ blockHeader: sampleBlockHeader });
expect(blockEventHandler['_lastSentCCUTxID']).toBe('txID');
expect(blockEventHandler['_lastSentCCM']).toEqual({});
expect(blockEventHandler['_lastSentCCM']).toEqual({
nonce: BigInt(1),
});
});
});

Expand Down
4 changes: 0 additions & 4 deletions framework-plugins/lisk-framework-chain-connector-plugin/test/unit/ccu_handler.spec.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -837,10 +837,6 @@ describe('CCUHandler', () => {

expect(result).toEqual(ccuTx.id.toString('hex'));
expect(chainConnectorDBMock.setCCUTransaction).toHaveBeenCalledWith(ccuTx.toObject());
expect((initArgs.logger as Logger).info).toHaveBeenCalledWith(
{ transactionID: result },
'Sent CCU transaction',
);
});
});

Expand Down

0 comments on commit 053a4e0

Please sign in to comment.