diff --git a/packages/composer-connector-hlfv1/lib/hlfconnection.js b/packages/composer-connector-hlfv1/lib/hlfconnection.js index 260044d23a..716ca67ba0 100644 --- a/packages/composer-connector-hlfv1/lib/hlfconnection.js +++ b/packages/composer-connector-hlfv1/lib/hlfconnection.js @@ -102,6 +102,12 @@ class HLFConnection extends Connection { // don't log the client, channel, caClient objects here they're too big LOG.entry(method, connectionManager, connectionProfile, businessNetworkIdentifier, connectOptions); + if (this.businessNetworkIdentifier) { + LOG.info(method, `Creating a connection using profile ${connectionProfile} to network ${businessNetworkIdentifier}`); + } else { + LOG.info(method, `Creating a connection using profile ${connectionProfile} to fabric (no business network)`); + } + // Validate all the arguments. if (!connectOptions) { throw new Error('connectOptions not specified'); @@ -141,6 +147,11 @@ class HLFConnection extends Connection { disconnect() { const method = 'disconnect'; LOG.entry(method); + if (this.businessNetworkIdentifier) { + LOG.info(method, `Disconnecting the connection to ${this.businessNetworkIdentifier}`); + } else { + LOG.info(method, 'Disconnecting the connection to fabric (no business network)'); + } if (this.exitListener) { process.removeListener('exit', this.exitListener); @@ -922,7 +933,11 @@ class HLFConnection extends Connection { let txId = this.client.newTransactionID(); const t0 = Date.now(); + LOG.perf(method, `start of querying chaincode ${functionName}(${args})`, txId, t0); + let result = await this.queryHandler.queryChaincode(txId, functionName, args); + + // need to know which query was executed, otherwise just need to know which function was executed. LOG.perf(method, `Total duration for queryChaincode to ${functionName}: `, txId, t0); LOG.exit(method, result ? result : null); return result ? result : null; @@ -978,8 +993,8 @@ class HLFConnection extends Connection { let eventHandler; let validResponses; - let t0 = Date.now(); + LOG.perf(method, `start of chaincode invocation ${functionName}(${args})`, txId, t0); try { LOG.debug(method, 'checking the event hub strategy'); await this._checkEventHubStrategy(); @@ -1000,7 +1015,7 @@ class HLFConnection extends Connection { fcn: functionName, args: args }; - LOG.perf(method, 'Total duration to initialize channel: ', txId, t0); + LOG.perf(method, 'Total duration to initialize: ', txId, t0); t0 = Date.now(); let results; diff --git a/packages/composer-connector-hlfv1/lib/hlfqueryhandler.js b/packages/composer-connector-hlfv1/lib/hlfqueryhandler.js index 2a9e597146..6aeddfd860 100644 --- a/packages/composer-connector-hlfv1/lib/hlfqueryhandler.js +++ b/packages/composer-connector-hlfv1/lib/hlfqueryhandler.js @@ -139,7 +139,9 @@ class HLFQueryHandler { args: args }; + const t0 = Date.now(); let payloads = await this.connection.channel.queryByChaincode(request); + LOG.perf(method, `Total duration for node-sdk queryByChaincode to ${functionName}: `, txId, t0); LOG.debug(method, `Received ${payloads.length} payloads(s) from querying the composer runtime chaincode`); if (!payloads.length) { LOG.error(method, 'No payloads were returned from the query request:' + functionName); diff --git a/packages/composer-connector-hlfv1/lib/hlftxeventhandler.js b/packages/composer-connector-hlfv1/lib/hlftxeventhandler.js index d37f2ba031..e7cfde960d 100644 --- a/packages/composer-connector-hlfv1/lib/hlftxeventhandler.js +++ b/packages/composer-connector-hlfv1/lib/hlftxeventhandler.js @@ -120,9 +120,9 @@ class HLFTxEventHandler { LOG.error(method, msg); throw Error(msg); } - LOG.exit(method); + } else { + LOG.warn(method, `No event hubs available to listen on to wait for a commit for transaction '${this.txId}'`); } - LOG.warn(method, `No event hubs available to listen on to wait for a commit for transaction '${this.txId}'`); LOG.exit(method); } diff --git a/packages/composer-connector-hlfv1/test/hlfconnection.js b/packages/composer-connector-hlfv1/test/hlfconnection.js index fa4f136c43..d9616391d0 100644 --- a/packages/composer-connector-hlfv1/test/hlfconnection.js +++ b/packages/composer-connector-hlfv1/test/hlfconnection.js @@ -56,12 +56,12 @@ describe('HLFConnection', () => { let mockPeer1, mockPeer2, mockPeer3, mockEventHub1, mockEventHub2, mockEventHub3, mockQueryHandler; let connectOptions; let connection; - let mockTransactionID, logWarnSpy, logErrorSpy; + let mockTransactionID, logWarnSpy, logErrorSpy, logInfoSpy, LOG; beforeEach(() => { sandbox = sinon.sandbox.create(); clock = sinon.useFakeTimers(); - const LOG = Logger.getLog('HLFConnection'); + LOG = Logger.getLog('HLFConnection'); logWarnSpy = sandbox.spy(LOG, 'warn'); logErrorSpy = sandbox.spy(LOG, 'error'); mockConnectionManager = sinon.createStubInstance(HLFConnectionManager); @@ -194,6 +194,18 @@ describe('HLFConnection', () => { connection = new HLFConnection(mockConnectionManager, 'hlfabric1', mockBusinessNetwork.getName(), {'x-requiredEventHubs': 'fred'}, mockClient, mockChannel, mockCAClient); connection.requiredEventHubs.should.equal(1); }); + + it('should log at info a fabric level connection being created', () => { + logInfoSpy = sandbox.spy(LOG, 'info'); + connection = new HLFConnection(mockConnectionManager, 'hlfabric1', null, {'x-requiredEventHubs': 'fred'}, mockClient, mockChannel, mockCAClient); + sinon.assert.calledWith(logInfoSpy, 'constructor', sinon.match(/no business network/)); + }); + + it('should log at info a business network level connection being created', () => { + logInfoSpy = sandbox.spy(LOG, 'info'); + connection = new HLFConnection(mockConnectionManager, 'hlfabric1', 'test-business-network', {'x-requiredEventHubs': 'fred'}, mockClient, mockChannel, mockCAClient); + sinon.assert.calledWith(logInfoSpy, 'constructor', sinon.match(/test-business-network/)); + }); }); describe('#_connectToEventHubs', () => { @@ -638,6 +650,20 @@ describe('HLFConnection', () => { sinon.assert.calledTwice(connection._disconnect); }); + it('should log at info a fabric level connection being disconnected', () => { + logInfoSpy = sandbox.spy(LOG, 'info'); + connection = new HLFConnection(mockConnectionManager, 'hlfabric1', null, {'x-requiredEventHubs': 'fred'}, mockClient, mockChannel, mockCAClient); + connection.disconnect(); + sinon.assert.calledWith(logInfoSpy.secondCall, 'disconnect', sinon.match(/no business network/)); + }); + + it('should log at info a business network level connection being created', () => { + logInfoSpy = sandbox.spy(LOG, 'info'); + connection = new HLFConnection(mockConnectionManager, 'hlfabric1', 'test-business-network', {'x-requiredEventHubs': 'fred'}, mockClient, mockChannel, mockCAClient); + connection.disconnect(); + sinon.assert.calledWith(logInfoSpy.secondCall, 'disconnect', sinon.match(/test-business-network/)); + }); + }); describe('#_disconnect', () => { diff --git a/packages/composer-connector-hlfv1/test/hlfqueryhandler.js b/packages/composer-connector-hlfv1/test/hlfqueryhandler.js index 56d374d814..38c24cf747 100644 --- a/packages/composer-connector-hlfv1/test/hlfqueryhandler.js +++ b/packages/composer-connector-hlfv1/test/hlfqueryhandler.js @@ -46,6 +46,7 @@ describe('HLFQueryHandler', () => { mockPeer3.index = 3; mockConnection = sinon.createStubInstance(HLFConnection); mockTransactionID = sinon.createStubInstance(TransactionID); + mockTransactionID.getTransactionID.returns('0987654321'); mockChannel = sinon.createStubInstance(Channel); mockConnection.channel = mockChannel; mockConnection.getChannelPeersInOrg.withArgs([FABRIC_CONSTANTS.NetworkConfig.CHAINCODE_QUERY_ROLE]).returns([mockPeer2, mockPeer1, mockPeer3]); diff --git a/packages/composer-connector-hlfv1/test/hlftxeventhandler.js b/packages/composer-connector-hlfv1/test/hlftxeventhandler.js index 3f214d86bf..a043773f88 100644 --- a/packages/composer-connector-hlfv1/test/hlftxeventhandler.js +++ b/packages/composer-connector-hlfv1/test/hlftxeventhandler.js @@ -175,7 +175,7 @@ describe('HLFTxEventHandler', () => { }); }); - it('Should handle a transaction listener error response all event hubs and event hubs required', async () => { + it('Should handle a transaction listener error response from all event hubs and event hubs required', async () => { sandbox.stub(global, 'setTimeout'); sandbox.stub(global, 'clearTimeout'); const ehc = sandbox.stub(HLFUtil, 'eventHubConnected'); @@ -194,7 +194,7 @@ describe('HLFTxEventHandler', () => { sinon.assert.calledTwice(logWarnSpy); }); - it('Should handle a transaction listener error response all event hubs but no event hubs required', async () => { + it('Should handle a transaction listener error response from all event hubs but no event hubs required', async () => { sandbox.stub(global, 'setTimeout'); sandbox.stub(global, 'clearTimeout'); const ehc = sandbox.stub(HLFUtil, 'eventHubConnected'); @@ -214,7 +214,7 @@ describe('HLFTxEventHandler', () => { } catch(err) { should.fail(null,null,`${err} unexpected`); } - sinon.assert.calledThrice(logWarnSpy); + sinon.assert.calledTwice(logWarnSpy); }); it('Should handle a transaction listener error response on one but not all of the event hubs', async () => {