Improve logging

bridge timeout probably too low for real world?

Author: jtakalai

src/dataunion/Contracts.ts

@@ -12,7 +12,7 @@ import { BigNumber } from '@ethersproject/bignumber'
 import StreamrEthereum from '../Ethereum'
 import { StreamrClient } from '../StreamrClient'
 
-const log = debug('StreamrClient::DataUnion')
+const log = debug('StreamrClient::Contracts')
 
 function validateAddress(name: string, address: EthereumAddress) {
     if (!isAddress(address)) {
@@ -149,7 +149,7 @@ export class Contracts {
 
         const [vArray, rArray, sArray]: Todo = [[], [], []]
         signatures.forEach((signature: string, i) => {
-            log(`  Signature ${i}: ${signature} (len=${signature.length}=${signature.length / 2 - 1} bytes)`)
+            log(`  Signature ${i}: ${signature} (len=${signature.length} = ${signature.length / 2 - 1} bytes)`)
             rArray.push(signature.substr(2, 64))
             sArray.push(signature.substr(66, 64))
             vArray.push(signature.substr(130, 2))

src/dataunion/DataUnion.ts

@@ -624,7 +624,7 @@ export class DataUnion {
         if (!payForTransport) {
             // expect someone else to do the transport for us (corresponds to dataUnion.freeWithdraw=true)
             if (waitUntilTransportIsComplete) {
-                log(`Waiting for balance ${balanceBefore.toString()} to change`)
+                log(`Waiting for balance ${balanceBefore.toString()} to change (poll every ${pollingIntervalMs}ms, timeout after ${retryTimeoutMs}ms)`)
                 await until(async () => !(await getBalanceFunc()).eq(balanceBefore), retryTimeoutMs, pollingIntervalMs)
                     .catch((e) => { throw e.message.startsWith('Timeout') ? new Error(`Timeout: Bridge did not transport withdraw message as expected. Fix: DataUnion.transportMessage("${messageHash}")`) : e })
                 return null

test/integration/dataunion/withdraw.test.ts

@@ -189,22 +189,26 @@ describe('DataUnion withdraw', () => {
         // emulate the bridge-sponsored withdrawals
         beforeAll(() => {
             if (!payForTransport && waitUntilTransportIsComplete) {
+                log('Starting the simulated bridge-sponsored signature transport process')
                 // event UserRequestForSignature(bytes32 indexed messageId, bytes encodedData)
                 const signatureRequestEventSignature = '0x520d2afde79cbd5db58755ac9480f81bc658e5c517fcae7365a3d832590b0183'
                 const sidechainAmbAddress = '0xaFA0dc5Ad21796C9106a36D68f69aAD69994BB64'
                 providerSidechain.on({
                     address: sidechainAmbAddress,
                     topics: [signatureRequestEventSignature]
                 }, async (event) => {
-                    const message = defaultAbiCoder.decode(['bytes'], event.data)[0] // messageId is indexed so it's in topics, only encodedData is in data
+                    log(`Observed signature request for message id=${event.topic[1]}`) // messageId is indexed so it's in topics...
+                    const message = defaultAbiCoder.decode(['bytes'], event.data)[0] // ...only encodedData is in data
                     const hash = keccak256(message)
                     const adminClient = new StreamrClient(config.clientOptions)
                     await adminClient.getDataUnion('0x0000000000000000000000000000000000000000').transportMessage(hash)
+                    log(`Transported message hash=${hash}`)
                 })
             }
         })
         afterAll(() => {
             if (!payForTransport && waitUntilTransportIsComplete) {
+                log('Stopping the simulated bridge-sponsored signature transport process')
                 providerSidechain.removeAllListeners()
             }
         })