Log (rsksmart#97)

* Added logs in log.debug level

src/common/ContractInteractor.ts

@@ -1,5 +1,6 @@
 import Common from 'ethereumjs-common'
 import Web3 from 'web3'
+import log from 'loglevel'
 import { BlockTransactionString } from 'web3-eth'
 import { EventData, PastEventOptions } from 'web3-eth-contract'
 import { PrefixedHexString, TransactionOptions } from 'ethereumjs-tx'
@@ -147,15 +148,18 @@ export default class ContractInteractor {
   getProvider (): provider { return this.provider }
 
   async init (): Promise<void> {
+    log.debug('Contract Interactor - Initializing')
     if (this.isInitialized()) {
-      throw new Error('_init was already called')
+      throw new Error('_init has already called')
     }
     await this._initializeContracts()
+    log.debug('Contract Interactor - Initialized succesfully')
     await this._validateCompatibility().catch(err => console.log('WARNING: beta ignore version compatibility', err.message))
     const chain = await this.web3.eth.net.getNetworkType()
     this.chainId = await this.getAsyncChainId()
     this.networkId = await this.web3.eth.net.getId()
     this.networkType = await this.web3.eth.net.getNetworkType()
+    log.debug(`Contract Interactor - Using chainId: ${this.chainId}, netowrkId:${this.networkId} , networkType:${this.networkType} `)
     // chain === 'private' means we're on ganache, and ethereumjs-tx.Transaction doesn't support that chain type
     this.rawTxOptions = getRawTxOptions(this.chainId, this.networkId, chain)
   }
@@ -187,12 +191,15 @@ export default class ContractInteractor {
   async _initializeContracts (): Promise<void> {
     if (this.config.relayHubAddress !== constants.ZERO_ADDRESS) {
       this.relayHubInstance = await this._createRelayHub(this.config.relayHubAddress)
+      log.debug(`Contract Interactor - Relay Hub initialized: ${this.relayHubInstance.address}`)
     }
     if (this.config.relayVerifierAddress !== constants.ZERO_ADDRESS) {
       this.relayVerifierInstance = await this._createRelayVerifier(this.config.relayVerifierAddress)
+      log.debug(`Contract Interactor - Relay Verifier initialized: ${this.relayVerifierInstance.address}`)
     }
     if (this.config.deployVerifierAddress !== constants.ZERO_ADDRESS) {
       this.deployVerifierInstance = await this._createDeployVerifier(this.config.deployVerifierAddress)
+      log.debug(`Contract Interactor - Deploy Verifier initialized: ${this.deployVerifierInstance.address}`)
     }
 
     console.log('Contracts initialized correctly')

src/relayclient/KnownRelaysManager.ts

@@ -49,9 +49,13 @@ export class KnownRelaysManager {
 
   async refresh (): Promise<void> {
     this._refreshFailures()
+    log.debug('KnownRelaysManager - Refresh failures done')
     const recentlyActiveRelayManagers = await this._fetchRecentlyActiveRelayManagers()
+    log.debug('KnownRelaysManager - Fetched recently active Relay Managers done')
     this.preferredRelayers = this.config.preferredRelays.map(relayUrl => { return { relayUrl } })
     this.allRelayers = await this.getRelayInfoForManagers(recentlyActiveRelayManagers)
+    log.debug('KnownRelaysManager - Get relay info for Managers done')
+    log.debug('KnownRelaysManager - Refresh done')
   }
 
   async getRelayInfoForManagers (relayManagers: Set<Address>): Promise<RelayRegisteredEventInfo[]> {

src/relayclient/RelayClient.ts

@@ -379,6 +379,8 @@ export class RelayClient {
 
   async relayTransaction (transactionDetails: EnvelopingTransactionDetails): Promise<RelayingResult> {
     await this._init()
+    log.debug('Relay Client - Relaying transaction')
+    log.debug(`Relay Client - Relay Hub:${transactionDetails.relayHub}`)
     // TODO: should have a better strategy to decide how often to refresh known relays
     this.emit(new RefreshRelaysEvent())
     await this.knownRelaysManager.refresh()
@@ -395,14 +397,15 @@ export class RelayClient {
       const internalCallCost = await this.contractInteractor.estimateDestinationContractCallGas(this.getEstimateGasParams(transactionDetails))
       transactionDetails.gas = toHex(internalCallCost)
     }
-
+    log.debug(`Relay Client - Estimated gas for relaying: ${transactionDetails.gas}`)
     const relaySelectionManager = await new RelaySelectionManager(transactionDetails, this.knownRelaysManager, this.httpClient, this.pingFilter, this.config).init()
     const count = relaySelectionManager.relaysLeft().length
     this.emit(new DoneRefreshRelaysEvent(count))
     if (count === 0) {
       throw new Error('no registered relayers')
     }
     const relayingErrors = new Map<string, Error>()
+    log.debug('Relay Client - Selecting active relay')
     while (true) {
       let relayingAttempt: RelayingAttempt | undefined
       const activeRelay = await relaySelectionManager.selectNextRelay()
@@ -420,6 +423,7 @@ export class RelayClient {
           relayingErrors.set(activeRelay.relayInfo.relayUrl, relayingAttempt.error ?? new Error('No error reason was given'))
           continue
         }
+        log.debug('Relay Client - Relayed done')
       }
       return {
         transaction: relayingAttempt?.transaction,

src/relayclient/RelayProvider.ts

@@ -89,6 +89,7 @@ export class RelayProvider implements HttpProvider {
           throw new Error('Enveloping cannot relay contract deployment transactions. Add {from: accountWithRBTC, useEnveloping: false}.')
         }
         this._ethSendTransaction(payload, callback)
+        log.debug('Relay Provider - Transaction sent')
         return
       }
       if (payload.method === 'eth_getTransactionReceipt') {
@@ -129,6 +130,7 @@ export class RelayProvider implements HttpProvider {
    * @returns The transaction hash
    */
   async deploySmartWallet (transactionDetails: EnvelopingTransactionDetails): Promise<string> {
+    log.debug('Relay Provider - Deploying Smart wallet')
     let isSmartWalletDeployValue = transactionDetails.isSmartWalletDeploy
     let relayHubValue = transactionDetails.relayHub
     let onlyPreferredRelaysValue = transactionDetails.onlyPreferredRelays
@@ -162,9 +164,12 @@ export class RelayProvider implements HttpProvider {
       }
     }
 
+    log.debug(`Relay Provider - Relay hub: ${transactionDetails.relayHub}`)
+
     const tokenGas = transactionDetails.tokenGas ?? '0'
     const tokenContract = transactionDetails.tokenContract ?? constants.ZERO_ADDRESS
-
+    log.debug(`Relay Provider - Token gas: ${tokenGas}`)
+    log.debug(`Relay Provider - Token contract: ${tokenContract}`)
     if (tokenContract !== constants.ZERO_ADDRESS &&
       toBN(transactionDetails.tokenAmount ?? '0').gt(toBN('0')) &&
       toBN(tokenGas).isZero() &&
@@ -175,10 +180,12 @@ export class RelayProvider implements HttpProvider {
     }
 
     try {
+      log.debug('Relay Provider - Relaying transaction started')
       const relayingResult = await this.relayClient.relayTransaction(transactionDetails)
       if (relayingResult.transaction != null) {
         const txHash: string = relayingResult.transaction.hash(true).toString('hex')
         const hash = `0x${txHash}`
+        log.debug(`Relay Provider - Transaction relay done, txHash: ${hash}`)
         return hash
       } else {
         const message = `Failed to relay call. Results:\n${_dumpRelayingResult(relayingResult)}`
@@ -259,6 +266,7 @@ export class RelayProvider implements HttpProvider {
 
   _ethSendTransaction (payload: JsonRpcPayload, callback: JsonRpcCallback): void {
     log.info('calling sendAsync' + JSON.stringify(payload))
+    log.debug('Relay Provider - _ethSendTransaction called')
     let transactionDetails: EnvelopingTransactionDetails = payload.params[0]
 
     let callForwarderValue = transactionDetails.callForwarder
@@ -299,6 +307,9 @@ export class RelayProvider implements HttpProvider {
       gas: gasToSend // it is either undefined or a user-entered value
     }
 
+    log.debug(`Relay Provider - Relay hub: ${transactionDetails.relayHub}`)
+    log.debug(`Relay Provider - callForwarder: ${transactionDetails.callForwarder}`)
+
     this.relayClient.relayTransaction(transactionDetails)
       .then((relayingResult) => {
         if (relayingResult.transaction !== undefined && relayingResult.transaction !== null) {
@@ -342,6 +353,9 @@ export class RelayProvider implements HttpProvider {
     const txHash: string = transaction.hash(true).toString('hex')
     const hash = `0x${txHash}`
     const id = (typeof request.id === 'string' ? parseInt(request.id) : request.id) ?? -1
+    log.debug('Relay Provider - rpc message sent, jsonRpcResult')
+    log.debug('Relay Provider - txHash: ' + hash)
+    log.debug('Relay Provider - id: ' + id.toString())
     return {
       jsonrpc: '2.0',
       id,

src/relayserver/RelayServer.ts

@@ -275,6 +275,8 @@ export class RelayServer extends EventEmitter {
   }
 
   async validateViewCallSucceeds (method: any, req: RelayTransactionRequest|DeployTransactionRequest, maxPossibleGas: BN): Promise<void> {
+    log.debug('Relay Server - Request sent to the worker')
+    log.debug('Relay Server - req: ', req)
     try {
       await method.call({
         from: this.workerAddress,
@@ -424,12 +426,14 @@ export class RelayServer extends EventEmitter {
     if (this.initialized) {
       throw new Error('_init was already called')
     }
+    log.debug('Relay Server - Relay Server initializing')
 
     await this.transactionManager._init()
+    log.debug('Relay Server - Transaction Manager initialized')
     await this._initTrustedVerifiers(this.config.trustedVerifiers)
     this.relayHubContract = this.contractInteractor.relayHubInstance
-
     const relayHubAddress = this.relayHubContract.address
+    log.debug(`Relay Server - Relay hub: ${relayHubAddress}`)
     const code = await this.contractInteractor.getCode(relayHubAddress)
     if (code.length < 10) {
       this.fatal(`No RelayHub deployed at address ${relayHubAddress}.`)
@@ -445,9 +449,12 @@ export class RelayServer extends EventEmitter {
       this.workerAddress
     )
     await this.registrationManager.init()
+    log.debug('Relay Server - Registration manager initialized')
 
     this.chainId = this.contractInteractor.getChainId()
     this.networkId = this.contractInteractor.getNetworkId()
+    log.debug(`Relay Server - chainId: ${this.chainId}`)
+    log.debug(`Relay Server - networkId: ${this.networkId}`)
 
     /* TODO CHECK against RSK ChainId
     if (this.config.devMode && (this.chainId < 1000 || this.networkId < 1000)) {

src/relayserver/runServer.ts

@@ -8,6 +8,7 @@ import { TxStoreManager, TXSTORE_FILENAME } from './TxStoreManager'
 import ContractInteractor from '../common/ContractInteractor'
 import { configure } from '../relayclient/Configurator'
 import { parseServerConfig, resolveServerConfig, ServerConfigParams, ServerDependencies } from './ServerConfigParams'
+import log from 'loglevel'
 
 function error (err: string): never {
   console.error(err)
@@ -30,7 +31,9 @@ async function run (): Promise<void> {
     }
 
     web3provider = new Web3.providers.HttpProvider(conf.rskNodeUrl)
+    log.debug('runServer() - web3Provider done')
     config = await resolveServerConfig(conf, web3provider) as ServerConfigParams
+    log.debug('runServer() - config done')
     if (trustedVerifiers.length > 0) {
       config.trustedVerifiers = trustedVerifiers
     }
@@ -46,13 +49,15 @@ async function run (): Promise<void> {
 
   const managerKeyManager = new KeyManager(1, workdir + '/manager')
   const workersKeyManager = new KeyManager(1, workdir + '/workers')
+  log.debug('runServer() - manager and workers configured')
   const txStoreManager = new TxStoreManager({ workdir })
   const contractInteractor = new ContractInteractor(web3provider, configure({
     relayHubAddress: config.relayHubAddress,
     deployVerifierAddress: config.deployVerifierAddress,
     relayVerifierAddress: config.relayVerifierAddress
   }))
   await contractInteractor.init()
+  log.debug('runServer() - contract interactor initilized')
 
   const dependencies: ServerDependencies = {
     txStoreManager,
@@ -63,8 +68,10 @@ async function run (): Promise<void> {
 
   const relayServer = new RelayServer(config, dependencies)
   await relayServer.init()
+  log.debug('runServer() - Relay Server initialized')
   const httpServer = new HttpServer(config.port, relayServer)
   httpServer.start()
+  log.debug('runServer() - Relay Server started')
 }
 
 // eslint-disable-next-line @typescript-eslint/no-floating-promises