From 94bea08149b7178bc35c5dadbeb6753737db6f92 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Emanuel=20Tesa=C5=99?= Date: Mon, 6 Nov 2023 19:16:05 +0100 Subject: [PATCH] Improve heartbeat log (#108) --- .../pusher/src/heartbeat/heartbeat.test.ts | 80 ++++++++++++------- packages/pusher/src/heartbeat/heartbeat.ts | 44 ++++++---- packages/pusher/src/state.ts | 4 +- packages/pusher/test/fixtures.ts | 29 +++---- 4 files changed, 94 insertions(+), 63 deletions(-) diff --git a/packages/pusher/src/heartbeat/heartbeat.test.ts b/packages/pusher/src/heartbeat/heartbeat.test.ts index 8e159d3d..aec9c2b9 100644 --- a/packages/pusher/src/heartbeat/heartbeat.test.ts +++ b/packages/pusher/src/heartbeat/heartbeat.test.ts @@ -3,13 +3,13 @@ import { join } from 'node:path'; import * as promiseUtilsModule from '@api3/promise-utils'; -import { config, parseHeartbeatLog } from '../../test/fixtures'; +import { config, verifyHeartbeatLog } from '../../test/fixtures'; import * as stateModule from '../state'; import * as configModule from '../validation/config'; import { heartbeatLogger } from './logger'; -import { initiateHeartbeat, logHeartbeat, createHash } from '.'; +import { initiateHeartbeat, logHeartbeat, type HeartbeatPayload, stringifyUnsignedHeartbeatPayload } from '.'; // eslint-disable-next-line jest/no-hooks beforeEach(() => { @@ -21,17 +21,17 @@ afterEach(() => { }); describe(logHeartbeat.name, () => { - const expectedLogMessage = [ - '0xbF3137b0a7574563a23a8fC8badC6537F98197CC', - 'test', - '0.1.0', - '1674172803', - '1674172800', - '0x126e768ba244efdb790d63a76821047e163dfc502ace09b2546a93075594c286', - '0x14f123ec1006bace8f8971cd8c94eb022b9bb0e1364e88ae4e8562a5f02de43e35dd4ecdefc976595eba5fec3d04222a0249e876453599b27847e85e14ff77601b', - ].join(' - '); - it('sends the correct heartbeat log', async () => { + const expectedLogMessage: HeartbeatPayload = { + airnode: '0xbF3137b0a7574563a23a8fC8badC6537F98197CC', + stage: 'test', + nodeVersion: '0.1.0', + currentTimestamp: '1674172803', + deploymentTimestamp: '1674172800', + configHash: '0x126e768ba244efdb790d63a76821047e163dfc502ace09b2546a93075594c286', + signature: + '0x24467037db96b652286c30c39ee9611faff07e1c17916f5c154ea7a27dfbc32f308969bdadf586bdaee0951b84819633e126a4fc72e3aa2e98a6eda95ce640081b', + }; const rawConfig = JSON.parse(readFileSync(join(__dirname, '../../config/pusher.example.json'), 'utf8')); jest.spyOn(configModule, 'loadRawConfig').mockReturnValue(rawConfig); const state = stateModule.getInitialState(config); @@ -41,27 +41,51 @@ describe(logHeartbeat.name, () => { await logHeartbeat(); - expect(heartbeatLogger.info).toHaveBeenCalledWith(expectedLogMessage); + expect(heartbeatLogger.info).toHaveBeenCalledWith('Sending heartbeat log', expectedLogMessage); }); +}); - it('the heartbeat log can be parsed', () => { - const rawConfig = JSON.parse(readFileSync(join(__dirname, '../../config/pusher.example.json'), 'utf8')); - jest.spyOn(configModule, 'loadRawConfig').mockReturnValue(rawConfig); - const expectedHeartbeatPayload = { - airnodeAddress: '0xbF3137b0a7574563a23a8fC8badC6537F98197CC', - stage: 'test', - nodeVersion: '0.1.0', - heartbeatTimestamp: '1674172803', - deploymentTimestamp: '1674172800', - configHash: '0x126e768ba244efdb790d63a76821047e163dfc502ace09b2546a93075594c286', - signature: - '0x14f123ec1006bace8f8971cd8c94eb022b9bb0e1364e88ae4e8562a5f02de43e35dd4ecdefc976595eba5fec3d04222a0249e876453599b27847e85e14ff77601b', +describe(verifyHeartbeatLog.name, () => { + it('heartbeat payload can be parsed from JSON log', () => { + const jsonLog = { + context: { + airnode: '0xbF3137b0a7574563a23a8fC8badC6537F98197CC', + configHash: '0x126e768ba244efdb790d63a76821047e163dfc502ace09b2546a93075594c286', + currentTimestamp: '1674172803', + deploymentTimestamp: '1674172800', + nodeVersion: '0.1.0', + signature: + '0x24467037db96b652286c30c39ee9611faff07e1c17916f5c154ea7a27dfbc32f308969bdadf586bdaee0951b84819633e126a4fc72e3aa2e98a6eda95ce640081b', + stage: 'test', + }, + level: 'info', + message: 'Sending heartbeat log', + ms: '+0ms', + timestamp: '2023-01-20T00:00:03.000Z', }; + // The config hash is taken from config with all spaces removed. + const rawConfig = JSON.stringify( + JSON.parse(readFileSync(join(__dirname, '../../config/pusher.example.json'), 'utf8')) + ); - const heartbeatPayload = parseHeartbeatLog(expectedLogMessage); + expect(() => verifyHeartbeatLog(jsonLog.context, rawConfig)).not.toThrow(); + }); +}); - expect(heartbeatPayload).toStrictEqual(expectedHeartbeatPayload); - expect(heartbeatPayload.configHash).toBe(createHash(JSON.stringify(rawConfig))); +describe(stringifyUnsignedHeartbeatPayload.name, () => { + it('sorts the keys alphabetically', () => { + expect( + stringifyUnsignedHeartbeatPayload({ + airnode: '0xbF3137b0a7574563a23a8fC8badC6537F98197CC', + stage: 'test', + nodeVersion: '0.1.0', + currentTimestamp: '1674172803', + deploymentTimestamp: '1674172800', + configHash: '0x126e768ba244efdb790d63a76821047e163dfc502ace09b2546a93075594c286', + }) + ).toBe( + '{"airnode":"0xbF3137b0a7574563a23a8fC8badC6537F98197CC","configHash":"0x126e768ba244efdb790d63a76821047e163dfc502ace09b2546a93075594c286","currentTimestamp":"1674172803","deploymentTimestamp":"1674172800","nodeVersion":"0.1.0","stage":"test"}' + ); }); }); diff --git a/packages/pusher/src/heartbeat/heartbeat.ts b/packages/pusher/src/heartbeat/heartbeat.ts index 974e1894..fc4dcb9c 100644 --- a/packages/pusher/src/heartbeat/heartbeat.ts +++ b/packages/pusher/src/heartbeat/heartbeat.ts @@ -14,11 +14,27 @@ export const initiateHeartbeat = () => { if (!goLogHeartbeat.success) logger.error('Failed to log heartbeat', goLogHeartbeat.error); }, 1000 * 60); // Frequency is hardcoded to 1 minute. }; +export interface HeartbeatPayload { + airnode: string; + stage: string; + nodeVersion: string; + currentTimestamp: string; + deploymentTimestamp: string; + configHash: string; + signature: string; +} -export const signHeartbeat = async (airnodeWallet: ethers.Wallet, heartbeatPayload: unknown[]) => { +// We need to make sure the object is stringified in the same way every time, so we sort the keys alphabetically. +export const stringifyUnsignedHeartbeatPayload = (unsignedHeartbeatPayload: Omit) => + JSON.stringify(unsignedHeartbeatPayload, Object.keys(unsignedHeartbeatPayload).sort()); + +export const signHeartbeat = async ( + airnodeWallet: ethers.Wallet, + unsignedHeartbeatPayload: Omit +) => { logger.debug('Signing heartbeat payload'); - const signaturePayload = ethers.utils.arrayify(createHash(JSON.stringify(heartbeatPayload))); - return airnodeWallet.signMessage(signaturePayload); + const messageToSign = ethers.utils.arrayify(createHash(stringifyUnsignedHeartbeatPayload(unsignedHeartbeatPayload))); + return airnodeWallet.signMessage(messageToSign); }; export const createHash = (value: string) => ethers.utils.keccak256(ethers.utils.toUtf8Bytes(value)); @@ -27,7 +43,7 @@ export const logHeartbeat = async () => { logger.debug('Creating heartbeat log'); const rawConfig = loadRawConfig(); // We want to log the raw config, not the one with interpolated secrets. - const rawConfigHash = createHash(JSON.stringify(rawConfig)); + const configHash = createHash(JSON.stringify(rawConfig)); const { airnodeWallet, deploymentTimestamp, @@ -37,19 +53,19 @@ export const logHeartbeat = async () => { } = getState(); logger.debug('Creating heartbeat payload'); - const currentTimestamp = Math.floor(Date.now() / 1000); - const heartbeatPayload = [ - airnodeWallet.address, + const currentTimestamp = Math.floor(Date.now() / 1000).toString(); + const unsignedHeartbeatPayload = { + airnode: airnodeWallet.address, stage, nodeVersion, - currentTimestamp.toString(), - deploymentTimestamp.toString(), - rawConfigHash, - ]; - const heartbeatSignature = await signHeartbeat(airnodeWallet, heartbeatPayload); - const heartbeatLog = [...heartbeatPayload, heartbeatSignature].join(' - '); + currentTimestamp, + deploymentTimestamp, + configHash, + }; + const signature = await signHeartbeat(airnodeWallet, unsignedHeartbeatPayload); + const heartbeatPayload: HeartbeatPayload = { ...unsignedHeartbeatPayload, signature }; // The logs are sent to API3 for validation (that the data provider deployed deployed the correct configuration) and // monitoring purposes (whether the instance is running). - heartbeatLogger.info(heartbeatLog); + heartbeatLogger.info('Sending heartbeat log', heartbeatPayload); }; diff --git a/packages/pusher/src/state.ts b/packages/pusher/src/state.ts index e524c1c9..13718a2e 100644 --- a/packages/pusher/src/state.ts +++ b/packages/pusher/src/state.ts @@ -15,7 +15,7 @@ export interface State { // We persist the derived Airnode wallet in memory as a performance optimization. airnodeWallet: ethers.Wallet; // The timestamp of when the service was initialized. This can be treated as a "deployment" timestamp. - deploymentTimestamp: number; + deploymentTimestamp: string; } let state: State; @@ -88,7 +88,7 @@ export const getInitialState = (config: Config): State => { templateValues: buildTemplateStorages(config), apiLimiters: buildApiLimiters(config), airnodeWallet: ethers.Wallet.fromMnemonic(config.nodeSettings.airnodeWalletMnemonic), - deploymentTimestamp: Math.floor(Date.now() / 1000), + deploymentTimestamp: Math.floor(Date.now() / 1000).toString(), }; }; diff --git a/packages/pusher/test/fixtures.ts b/packages/pusher/test/fixtures.ts index b13526f3..c64c9af5 100644 --- a/packages/pusher/test/fixtures.ts +++ b/packages/pusher/test/fixtures.ts @@ -1,7 +1,9 @@ import type { AxiosResponse } from 'axios'; import { ethers } from 'ethers'; +import { omit } from 'lodash'; import packageJson from '../package.json'; +import { type HeartbeatPayload, createHash, stringifyUnsignedHeartbeatPayload } from '../src/heartbeat'; import type { SignedResponse, TemplateResponse } from '../src/sign-template-data'; import type { Config } from '../src/validation/schema'; @@ -186,25 +188,14 @@ export const signedApiResponse: Partial = { data: { count: 3 }, }; -export const parseHeartbeatLog = (logMessage: string) => { - const [airnodeAddress, stage, nodeVersion, heartbeatTimestamp, deploymentTimestamp, configHash, signature] = - logMessage.split(' - '); - +export const verifyHeartbeatLog = (heartbeatPayload: HeartbeatPayload, rawConfig: string) => { // Verify that the signature is valid. - const heartbeatPayload = [airnodeAddress, stage, nodeVersion, heartbeatTimestamp, deploymentTimestamp, configHash]; - const signaturePayload = ethers.utils.arrayify( - ethers.utils.keccak256(ethers.utils.toUtf8Bytes(JSON.stringify(heartbeatPayload))) - ); - const recoveredAddress = ethers.utils.verifyMessage(signaturePayload, signature!); - if (recoveredAddress !== airnodeAddress) throw new Error('Invalid signature'); + const unsignedHeartbeatPayload = omit(heartbeatPayload, 'signature'); + const messageToSign = ethers.utils.arrayify(createHash(stringifyUnsignedHeartbeatPayload(unsignedHeartbeatPayload))); + const expectedAirnodeAddress = ethers.utils.verifyMessage(messageToSign, heartbeatPayload.signature); + if (expectedAirnodeAddress !== heartbeatPayload.airnode) throw new Error('Invalid signature'); - return { - airnodeAddress, - stage, - nodeVersion, - deploymentTimestamp, - heartbeatTimestamp, - configHash, - signature, - }; + // Verify that the config hash is valid. + const expectedConfigHash = createHash(rawConfig); + if (expectedConfigHash !== heartbeatPayload.configHash) throw new Error('Invalid config hash'); };