Skip to content

Commit

Permalink
refactor: improve log format
Browse files Browse the repository at this point in the history
  • Loading branch information
linkdesu committed Oct 10, 2023
1 parent 9ec71f5 commit 828cb66
Show file tree
Hide file tree
Showing 10 changed files with 90 additions and 69 deletions.
1 change: 1 addition & 0 deletions .github/workflows/cd.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ on:
workflows: [ci]
types: [completed]
branches: [main, develop]
workflow_dispatch:

jobs:
deploy-to-mainnet:
Expand Down
1 change: 1 addition & 0 deletions config/default.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ CKB_WS_URL: 'ws://127.0.0.1:28114'
LARK_API_KEY: ''

loglevel: 'info'
env: ''

# Define the servers and its IP address, mainly used for making notification much more readable in lark.
servers: {}
Expand Down
2 changes: 2 additions & 0 deletions config/mainnet.yaml
Original file line number Diff line number Diff line change
@@ -1,4 +1,6 @@
---
env: mainnet

CellDeps:
# index-state-cell-type
- outPoint: { txHash: '0xe9116d651c371662b6e29e2102422e23f90656b8619df82c48b782ff4db43a37', index: '0x0' }
Expand Down
2 changes: 2 additions & 0 deletions config/testnet.yaml
Original file line number Diff line number Diff line change
@@ -1,4 +1,6 @@
---
env: testnet

CellDeps:
# index-state-cell-type
- outPoint: { txHash: '0x654f8a271dde2d99f548ff5b9369a55c0cfbe19a315efb5dacf34f72d7f3ea64', index: '0x0' }
Expand Down
6 changes: 3 additions & 3 deletions ecosystem.config.js
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,7 @@ function generateApp (name, entry, args, env) {
watch: false,
error_file: `logs/${appName}.stderr.log`,
out_file: `logs/${appName}.stdout.log`,
log_date_format: 'MM-DD HH:mm:ss',
// log_date_format: 'MM-DD HH:mm:ss',
kill_timeout: 10 * 1000, // ms
listen_timeout: 10 * 1000, // ms
max_memory_restart: '256M',
Expand All @@ -30,8 +30,8 @@ module.exports = {
* http://pm2.keymetrics.io/docs/usage/application-declaration/
*/
apps: [
generateApp('time', 'dist/main.js', 'update -t timestamp', process.env.NODE_ENV),
generateApp('height', 'dist/main.js', 'update -t blocknumber', process.env.NODE_ENV),
// generateApp('time', 'dist/main.js', 'update -t timestamp', process.env.NODE_ENV),
// generateApp('height', 'dist/main.js', 'update -t blocknumber', process.env.NODE_ENV),
generateApp('quote', 'dist/main.js', 'update -t quote', process.env.NODE_ENV),
]
}
1 change: 1 addition & 0 deletions src/config.ts
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@ interface Config {
LARK_API_KEY: string,

loglevel: string,
env: string,

// Define the servers and its IP address, mainly used for making notification much more readable in lark.
servers: any,
Expand Down
53 changes: 29 additions & 24 deletions src/controller/update.ts
Original file line number Diff line number Diff line change
Expand Up @@ -26,18 +26,20 @@ import { IndexStateModel } from '../model/index_state_model'
import { InfoModel } from '../model/info_model'
import { EMPTY_WITNESS_ARGS } from '@nervosnetwork/ckb-sdk-utils/lib/const'

async function findIndexStateCell (typeScript: CKBComponents.Script) {
async function findIndexStateCell (logger: Logger, typeScript: CKBComponents.Script) {
const indexStateCells = await getCells(typeScript, 'type')

if (indexStateCells.length > 1) {
// await notifyWithThrottle('index-state-cells-error', TIME_1_M * 60, 'Found more than one IndexStateCells on-chain, please recycle redundant cells as soon as possible.')
// await notifyWithThrottle(logger, 'index-state-cells-error', TIME_1_M * 60, 'Found more than one IndexStateCells on-chain, please recycle redundant cells as soon as possible.')
logger.warn('Found more than one IndexStateCells on-chain, please recycle redundant cells as soon as possible.')
}

const cell = indexStateCells[0]
const model = IndexStateModel.fromHex(cell.output_data)

if (model.total !== SUM_OF_INFO_CELLS) {
// await notifyWithThrottle('index-state-cells-error', TIME_1_M * 60, 'Total number of InfoCells is different from code and cell data, please update code as soon as possible.')
// await notifyWithThrottle(logger, 'index-state-cells-error', TIME_1_M * 60, 'Total number of InfoCells is different from code and cell data, please update code as soon as possible.')
logger.warn('Total number of InfoCells is different from code and cell data, please update code as soon as possible.')
}

return {
Expand All @@ -47,11 +49,12 @@ async function findIndexStateCell (typeScript: CKBComponents.Script) {
}
}

async function findInfoCell (typeScript: CKBComponents.Script, index: number) {
async function findInfoCell (logger: Logger, typeScript: CKBComponents.Script, index: number) {
const infoCells = await getCells(typeScript, 'type')

if (infoCells.length > SUM_OF_INFO_CELLS) {
// await notifyWithThrottle('info-cells-error', TIME_1_M * 60, `Found more than ${SUM_OF_INFO_CELLS} InfoCells on-chain, please recycle redundant cells as soon as possible.`)
// await notifyWithThrottle(logger, 'info-cells-error', TIME_1_M * 60, `Found more than ${SUM_OF_INFO_CELLS} InfoCells on-chain, please recycle redundant cells as soon as possible.`)
logger.warn(`Found more than ${SUM_OF_INFO_CELLS} InfoCells on-chain, please recycle redundant cells as soon as possible.`)
}

for (const cell of infoCells) {
Expand Down Expand Up @@ -82,12 +85,12 @@ export async function updateController (argv: Arguments<{ type: string }>) {
server.on('update', (data: RPC.Header) => {
(async () => {
if (txHash && waitedBlocks <= maxWaitingBlocks) {
logger.verbose('Found pending transaction, check if transaction committed ...', { txHash: txHash })
logger.verbose(`Found pending transaction ${txHash}, check if transaction committed ...`)

const tx = await getTransaction(txHash)
// tx maybe null
if (!tx || tx.txStatus.status !== 'committed') {
logger.info('Previous transaction is pending, wait for it.', { txHash: txHash })
logger.info(`${txHash} is pending, wait for it.`)
waitedBlocks++
return
}
Expand All @@ -96,7 +99,7 @@ export async function updateController (argv: Arguments<{ type: string }>) {
// Calculate new outputs_data of IndexStateCell and InfoCell
let resultOfIndex: { out_point: RPC.OutPoint, output: RPC.CellOutput, model: IndexStateModel }
try {
resultOfIndex = await findIndexStateCell(indexStateTypeScript)
resultOfIndex = await findIndexStateCell(logger, indexStateTypeScript)
} catch (e) {
logger.error(`Failed to find IndexStateCells: ${e.toString()}`)
return
Expand All @@ -107,7 +110,7 @@ export async function updateController (argv: Arguments<{ type: string }>) {

let resultOfInfo: { out_point: RPC.OutPoint, output: RPC.CellOutput, model: InfoModel }
try {
resultOfInfo = await findInfoCell(infoCellTypeScript, indexModel.index)
resultOfInfo = await findInfoCell(logger, infoCellTypeScript, indexModel.index)
} catch (e) {
logger.error(`Failed to find InfoCells: ${e.toString()}`)
return
Expand All @@ -124,17 +127,17 @@ export async function updateController (argv: Arguments<{ type: string }>) {
try {
infoModel.infoData = await getLatestTimestamp(data.number)
} catch (e) {
await notifyWithThreshold('fetch-timestamp-error', THEORETIC_BLOCK_1_M * 5, TIME_1_M * 5, `${e}`, 'Check if CKB node is offline and its JSON RPC is reachable.')
await notifyWithThreshold(logger, 'fetch-timestamp-error', THEORETIC_BLOCK_1_M * 5, TIME_1_M * 5, `${e}`, 'Check if CKB node is offline and its JSON RPC is reachable.')
return
}
since = dataToSince(infoModel.infoData, SinceFlag.AbsoluteTimestamp)
break
case 'quote':
try {
infoModel.infoData = await getCkbPrice()
infoModel.infoData = await getCkbPrice(logger)
} catch (e) {
logger.error(`Failed to fetch the quote from exchanges, the error is: ${e}`)
await notifyWithThreshold('fetch-quote-error', THEORETIC_BLOCK_1_M * 10, TIME_1_M * 10, `${e}`, 'Check if the coingecko API(https://api.coingecko.com/api/v3/simple/price?ids=nervos-network&vs_currencies=usd) is available.')
await notifyWithThreshold(logger, 'fetch-quote-error', THEORETIC_BLOCK_1_M * 10, TIME_1_M * 10, `${e}`, 'Check if the coingecko API(https://api.coingecko.com/api/v3/simple/price?ids=nervos-network&vs_currencies=usd) is available.')
return
}
break
Expand All @@ -153,15 +156,15 @@ export async function updateController (argv: Arguments<{ type: string }>) {

let collected
try {
collected = await collectInputs(lockScript, config.fee.update)
collected = await collectInputs(logger, lockScript, config.fee.update)
inputs = inputs.concat(collected.inputs)
} catch (e) {
if (e.toString().includes('capacity')) {
logger.error(`Collect inputs failed, expected ${config.fee.update} shannon but only ${collected.capacity} shannon found.`)
await notifyWithThreshold('collect-inputs-error', THEORETIC_BLOCK_1_M * 5, TIME_1_M * 5, `Collect inputs failed, expected ${config.fee.update} shannon but only ${collected.capacity} shannon found.`, 'Check if the balance of deploy address is enough.')
await notifyWithThreshold(logger, 'collect-inputs-error', THEORETIC_BLOCK_1_M * 5, TIME_1_M * 5, `Collect inputs failed, expected ${config.fee.update} shannon but only ${collected.capacity} shannon found.`, 'Check if the balance of deploy address is enough.')
} else {
logger.error(`Collect inputs error.(${e.toString()})`)
await notifyWithThreshold('collect-inputs-error', THEORETIC_BLOCK_1_M * 5, TIME_1_M * 5, `Collect inputs error.(${e.toString()})`, 'Check if ckb-indexer is offline and the get_cells interface is reachable.')
await notifyWithThreshold(logger, 'collect-inputs-error', THEORETIC_BLOCK_1_M * 5, TIME_1_M * 5, `Collect inputs error.(${e.toString()})`, 'Check if ckb-indexer is offline and the get_cells interface is reachable.')
}
return
}
Expand Down Expand Up @@ -210,7 +213,7 @@ export async function updateController (argv: Arguments<{ type: string }>) {
await ckb.loadDeps()
} catch (e) {
logger.error(`Load cell_deps from node RPC API failed.(${e})`)
await notifyWithThreshold('load-cell-deps-error', THEORETIC_BLOCK_1_M * 5, TIME_1_M * 5, `Load cell_deps from node RPC API failed.(${e})`, 'Check if CKB node is offline and its JSON RPC is reachable.')
await notifyWithThreshold(logger, 'load-cell-deps-error', THEORETIC_BLOCK_1_M * 5, TIME_1_M * 5, `Load cell_deps from node RPC API failed.(${e})`, 'Check if CKB node is offline and its JSON RPC is reachable.')
return
}

Expand All @@ -219,7 +222,7 @@ export async function updateController (argv: Arguments<{ type: string }>) {
signedRawTx = ckb.signTransaction(config[argv.type].PayersPrivateKey)(rawTx)
} catch (e) {
logger.error(`Sign transaction failed.(${e})`)
await notifyWithThrottle('sign-transaction-error', TIME_1_M * 10, `Sign transaction failed.(${e})`, 'Try to find out what the error message means it mostly because the private key is not match.')
await notifyWithThrottle(logger, 'sign-transaction-error', TIME_1_M * 10, `Sign transaction failed.(${e})`, 'Try to find out what the error message means it mostly because the private key is not match.')
return
}

Expand All @@ -236,15 +239,15 @@ export async function updateController (argv: Arguments<{ type: string }>) {
case -302:
case -1107:
// These error are caused by cell occupation, could retry automatically.
logger.warn(`Update cell failed.(${data.message})`, { code: data.code })
logger.warn(`Update cell failed.(${data.code}: ${data.message})`)
return
default:
logger.error(`Update cell failed.(${data.message})`, { code: data.code })
await notifyWithThrottle('update-error', TIME_1_M * 10, `Update cell failed.(${data.message})`, 'Try to find out what the error message means.')
logger.error(`Update cell failed.(${data.code}: ${data.message})`)
await notifyWithThrottle(logger, 'update-error', TIME_1_M * 10, `Update cell failed.(${data.message})`, 'Try to find out what the error message means.')
}
} catch (e) {
logger.error(`Update cell occurred unknown error.(${err})`)
await notifyWithThrottle('update-error', TIME_1_M * 10, `Update cell occurred unknown error.(${err})`, 'Try to find out what the error message means.')
await notifyWithThrottle(logger, 'update-error', TIME_1_M * 10, `Update cell occurred unknown error.(${err})`, 'Try to find out what the error message means.')

}
}
Expand Down Expand Up @@ -340,6 +343,7 @@ class Server extends EventEmitter {
// The key point here is eventTimeoutLimit, enlarge it is the only way
status.timer_notify = setTimeout(async () => {
await notifyLark(
this.logger,
`There is no new block for ${this.newBlockNotifyLimit / 1000} seconds.`,
`This problem occasionally occurs and can be safely ignored, a formal warning will be triggered afer ${this.newBlockWarnLimit / 1000} seconds.`,
false,
Expand All @@ -348,6 +352,7 @@ class Server extends EventEmitter {

status.timer_warn = setTimeout(async () => {
await notifyLark(
this.logger,
`There is no new block for ${this.newBlockWarnLimit / 1000} seconds.`,
'Check if CKB node is offline and the get_tip_header interface is reachable.',
true,
Expand All @@ -357,7 +362,7 @@ class Server extends EventEmitter {
}

protected async onClose (code: number, reason: string) {
this.logger.warn('Connection closed, will retry connecting later.', { code, reason })
this.logger.warn(`Connection closed, will retry connecting later.(${code}: ${reason})`)

setTimeout(() => {
clearTimeout(this.eventStatus.timer_notify)
Expand All @@ -368,7 +373,7 @@ class Server extends EventEmitter {

protected async onError (err: Error) {
this.logger.error(`Connection error occurred.(${err})`)
await notifyWithThrottle('ws-error', TIME_1_M * 10, `Connection error occurred.(${err})`, 'Check if CKB node is offline and the get_tip_header interface is reachable.')
await notifyWithThrottle(this.logger, 'ws-error', TIME_1_M * 10, `Connection error occurred.(${err})`, 'Check if CKB node is offline and the get_tip_header interface is reachable.')
}

protected heartbeat () {
Expand All @@ -377,7 +382,7 @@ class Server extends EventEmitter {

clearTimeout(status.timer)
status.timer = setTimeout(async () => {
await notifyWithThrottle('heartbeat', TIME_1_M * 10, 'Connection timeout.', 'Check if CKB node is offline and the get_tip_header interface is reachable.')
await notifyWithThrottle(this.logger, 'heartbeat', TIME_1_M * 10, 'Connection timeout.', 'Check if CKB node is offline and the get_tip_header interface is reachable.')
this.ws.terminate()
}, TIME_30_S)

Expand Down
8 changes: 8 additions & 0 deletions src/log.ts
Original file line number Diff line number Diff line change
@@ -1,9 +1,17 @@
import { createLogger, format, transports } from 'winston'

import config from './config'
import { getCurrentServer } from './utils/env'

const server = getCurrentServer();

export const rootLogger = createLogger({
level: config.loglevel,
defaultMeta: {
server: server,
pid: process.pid,
env: config.env,
},
format: format.combine(
format.metadata(),
format.timestamp(),
Expand Down
33 changes: 33 additions & 0 deletions src/utils/env.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,33 @@
import config from '../config';
import { networkInterfaces } from 'os';


export function getCurrentServer (): string {
const ip = getCurrentIP()
const servers = config.servers

if (servers && servers[ip]) {
return servers[ip]
} else {
return ip
}
}

export function getCurrentIP () {
const nets = networkInterfaces()
let address = 'parse failed'

for (const name of Object.keys(nets)) {
if (['eth', 'eno', 'ens', 'enp'].includes(name.substring(0, 3))) {
for (const net of nets[name]) {
if (net.family === 'IPv4' && !net.internal) {
address = net.address
break
}
}
}
}

return address
}

Loading

0 comments on commit 828cb66

Please sign in to comment.