Skip to content

Commit

Permalink
[Master] fix runtime logging, default to warn (hyperledger-archives#4439
Browse files Browse the repository at this point in the history 
)

Signed-off-by: Dave Kelsey <[email protected]>
  • Loading branch information
Dave Kelsey authored Oct 3, 2018
1 parent da12d08 commit a9be602
Show file tree
Hide file tree
Showing 12 changed files with 70 additions and 70 deletions.
2 changes: 1 addition & 1 deletion packages/composer-common/lib/connectionprofilemanager.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -128,7 +128,7 @@ class ConnectionProfileManager {
});
}
if (!connectionManager) {
LOG.verbose(METHOD, 'not located the module - final try ');
LOG.info(METHOD, 'not located the module - final try ');
// We still didn't find it, so try plain old require
// one last time.
connectionManager = new (require(mod))(this);
Expand Down
10 changes: 5 additions & 5 deletions packages/composer-runtime-hlfv1/lib/composer.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -97,12 +97,12 @@ class Composer {
let nodeContext = this._createContext(engine, stub);
await engine.init(nodeContext, fcn, params);
LOG.exit(method);
LOG.debug('@PERF ' + method, 'Total (ms) duration for txnID [' + stub.getTxID() + ']: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration for txnID [' + stub.getTxID() + ']: ' + (Date.now() - t0).toFixed(2));
return shim.success();
}
catch(err) {
LOG.error(method, err);
LOG.debug('@PERF ' + method, 'Total (ms) duration for txnID [' + stub.getTxID() + ']: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration for txnID [' + stub.getTxID() + ']: ' + (Date.now() - t0).toFixed(2));
return shim.error(err);
}
}
Expand All @@ -127,16 +127,16 @@ class Composer {
let payload = await engine.invoke(nodeContext, fcn, params);
if (payload !== null && payload !== undefined) {
LOG.exit(method, payload);
LOG.debug('@PERF ' + method, 'Total (ms) duration for txnID [' + stub.getTxID() + ']: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration for txnID [' + stub.getTxID() + ']: ' + (Date.now() - t0).toFixed(2));
return shim.success(Buffer.from(JSON.stringify(payload)));
}
LOG.exit(method);
LOG.debug('@PERF ' + method, 'Total (ms) duration for txnID [' + stub.getTxID() + ']: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration for txnID [' + stub.getTxID() + ']: ' + (Date.now() - t0).toFixed(2));
return shim.success();
}
catch(err) {
LOG.error(method, err);
LOG.debug('@PERF ' + method, 'Total (ms) duration for txnID [' + stub.getTxID() + ']: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration for txnID [' + stub.getTxID() + ']: ' + (Date.now() - t0).toFixed(2));
return shim.error(err);
}
}
Expand Down
20 changes: 10 additions & 10 deletions packages/composer-runtime-hlfv1/lib/nodedatacollection.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -52,7 +52,7 @@ class NodeDataCollection extends DataCollection {
let iterator = await this.stub.getStateByPartialCompositeKey(this.collectionID, []);
let results = await NodeUtils.getAllResults(iterator);
LOG.exit(method, results);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
return results;
}

Expand All @@ -72,12 +72,12 @@ class NodeDataCollection extends DataCollection {
if (value.length === 0) {
const newErr = new Error(`Object with ID '${id}' in collection with ID '${this.collectionID}' does not exist`);
LOG.error(method, newErr);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
throw newErr;
}
let retVal = JSON.parse(value.toString('utf8'));
LOG.exit(method, retVal);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
return retVal;
}

Expand All @@ -96,7 +96,7 @@ class NodeDataCollection extends DataCollection {
let value = await this.stub.getState(key);
let retVal = value.length !== 0;
LOG.exit(method, retVal);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
return retVal;
}

Expand All @@ -120,14 +120,14 @@ class NodeDataCollection extends DataCollection {
if (value.length !== 0) {
const newErr = new Error(`Failed to add object with ID '${id}' in collection with ID '${this.collectionID}' as the object already exists`);
LOG.error(method, newErr);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
throw newErr;
}
}
await this.stub.putState(key, Buffer.from(JSON.stringify(object)));

LOG.exit(method);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
}

/**
Expand All @@ -148,12 +148,12 @@ class NodeDataCollection extends DataCollection {
if (value.length === 0) {
const newErr = new Error(`Failed to update object with ID '${id}' in collection with ID '${this.collectionID}' as the object does not exist`);
LOG.error(method, newErr);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
throw newErr;
}
await this.stub.putState(key, Buffer.from(JSON.stringify(object)));
LOG.exit(method);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
}

/**
Expand All @@ -170,12 +170,12 @@ class NodeDataCollection extends DataCollection {
if (value.length === 0) {
const newErr = new Error(`Failed to delete object with ID '${id}' in collection with ID '${this.collectionID}' as the object does not exist`);
LOG.error(method, newErr);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
throw newErr;
}
await this.stub.deleteState(key);
LOG.exit(method);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
}
}

Expand Down
24 changes: 12 additions & 12 deletions packages/composer-runtime-hlfv1/lib/nodedataservice.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -57,17 +57,17 @@ class NodeDataService extends DataService {
if (value.length === 0) {
let result = await this._storeCollection(key, id);
LOG.exit(method, result);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
return result;
}
else {
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
throw new Error(`Failed to create collection with ID ${id} as it already exists`);
}
} else {
let result = await this._storeCollection(key, id);
LOG.exit(method, result);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
return result;
}
}
Expand All @@ -88,7 +88,7 @@ class NodeDataService extends DataService {
await this.stub.putState(key, Buffer.from(JSON.stringify({'id': id})));
let retVal = new NodeDataCollection(this, this.stub, id);
LOG.exit(method, retVal);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
return retVal;
}

Expand All @@ -104,13 +104,13 @@ class NodeDataService extends DataService {
let key = this.stub.createCompositeKey(collectionObjectType, [id]);
let exists = await this.existsCollection(id);
if (!exists) {
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
throw new Error(`Collection with ID ${id} does not exist`);
}
await this.clearCollection(id);
await this.stub.deleteState(key);
LOG.exit(method);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
}

/**
Expand All @@ -128,18 +128,18 @@ class NodeDataService extends DataService {
if (bypass) {
let retVal = new NodeDataCollection(this, this.stub, id);
LOG.exit(method, retVal);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
return retVal;
} else {
let key = this.stub.createCompositeKey(collectionObjectType, [id]);
let value = await this.stub.getState(key);
if (value.length === 0) {
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
throw new Error(`Collection with ID ${id} does not exist`);
}
let retVal = new NodeDataCollection(this, this.stub, id);
LOG.exit(method, retVal);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
return retVal;
}
}
Expand All @@ -159,7 +159,7 @@ class NodeDataService extends DataService {
let value = await this.stub.getState(key);
let retVal = value.length !== 0;
LOG.exit(method, retVal);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
return retVal;
}

Expand All @@ -178,7 +178,7 @@ class NodeDataService extends DataService {
let iterator = await this.stub.getQueryResult(query);
let results = await NodeUtils.getAllResults(iterator);
LOG.exit(method, results);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
return results;
}

Expand All @@ -194,7 +194,7 @@ class NodeDataService extends DataService {
let iterator = await this.stub.getStateByPartialCompositeKey(id, []);
await NodeUtils.deleteAllResults(iterator, this.stub);
LOG.exit(method);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
}
}

Expand Down
8 changes: 4 additions & 4 deletions packages/composer-runtime-hlfv1/lib/nodeloggingservice.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -110,7 +110,7 @@ class NodeLoggingService extends LoggingService {
* @return {String} clean string that can be used for setting up logging.
*/
mapCfg(string){
let DEFAULT = 'composer[error]:*';
let DEFAULT = 'composer[warn]:*';
// first split it up into elements based on ,
let details = string.split(/[\s,]+/);

Expand Down Expand Up @@ -173,19 +173,19 @@ class NodeLoggingService extends LoggingService {
debugString='composer[error]:*';
break;
case 'warning':
debugString='composer[warning]:*';
debugString='composer[warn]:*';
break;
case 'notice':
debugString='composer[info]:*';
break;
case 'info':
debugString='composer[verbose]:*';
debugString='composer[info]:*';
break;
case 'debug':
debugString='composer[debug]:*';
break;
default:
debugString='composer[error]:*';
debugString='composer[warn]:*';
break;
}
return debugString;
Expand Down
4 changes: 2 additions & 2 deletions packages/composer-runtime-hlfv1/lib/nodeutils.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -58,7 +58,7 @@ class NodeUtils {
LOG.warn(warnMsg);
}
LOG.exit(method, logResults);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
return results;
}
}
Expand Down Expand Up @@ -97,7 +97,7 @@ class NodeUtils {
LOG.warn(warnMsg);
}
LOG.exit(method, logResults);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
return results;
}
}
Expand Down
14 changes: 7 additions & 7 deletions packages/composer-runtime-hlfv1/test/nodeloggingservice.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -69,13 +69,13 @@ describe('NodeLoggingService', () => {
it('should return the default values', () => {
delete process.env.CORE_CHAINCODE_LOGGING_LEVEL;
let value = loggingService.getDefaultCfg();
value.debug.should.equal('composer[error]:*');
value.debug.should.equal('composer[warn]:*');
});

it('should return the default value if the enviroment variable is invalid', () => {
process.env.CORE_CHAINCODE_LOGGING_LEVEL='wibble';
let value = loggingService.getDefaultCfg();
value.debug.should.equal('composer[error]:*');
value.debug.should.equal('composer[warn]:*');
});

it('should map fabric container values to valid composer debug strings', () => {
Expand All @@ -87,13 +87,13 @@ describe('NodeLoggingService', () => {


process.env.CORE_CHAINCODE_LOGGING_LEVEL='WARNING';
loggingService.getDefaultCfg().debug.should.equal('composer[warning]:*');
loggingService.getDefaultCfg().debug.should.equal('composer[warn]:*');

process.env.CORE_CHAINCODE_LOGGING_LEVEL='NOTICE';
loggingService.getDefaultCfg().debug.should.equal('composer[info]:*');

process.env.CORE_CHAINCODE_LOGGING_LEVEL='INFO';
loggingService.getDefaultCfg().debug.should.equal('composer[verbose]:*');
loggingService.getDefaultCfg().debug.should.equal('composer[info]:*');

process.env.CORE_CHAINCODE_LOGGING_LEVEL='DEBUG';
loggingService.getDefaultCfg().debug.should.equal('composer[debug]:*');
Expand Down Expand Up @@ -148,7 +148,7 @@ describe('NodeLoggingService', () => {
});

describe('#mapCfg', async ()=>{
let expectedDefault = 'composer[error]:*';
let expectedDefault = 'composer[warn]:*';
it('should handle an empty string with default value',()=>{
loggingService.mapCfg('').should.equal(expectedDefault);
});
Expand All @@ -158,9 +158,9 @@ describe('NodeLoggingService', () => {
it('should handle a valid fabric value',()=>{
loggingService.mapCfg('CRITICAL').should.equal('composer[error]:*');
loggingService.mapCfg('ERROR').should.equal('composer[error]:*');
loggingService.mapCfg('WARNING').should.equal('composer[warning]:*');
loggingService.mapCfg('WARNING').should.equal('composer[warn]:*');
loggingService.mapCfg('NOTICE').should.equal('composer[info]:*');
loggingService.mapCfg('INFO').should.equal('composer[verbose]:*');
loggingService.mapCfg('INFO').should.equal('composer[info]:*');
loggingService.mapCfg('DEBUG').should.equal('composer[debug]:*');
});

Expand Down
8 changes: 4 additions & 4 deletions packages/composer-runtime/lib/accesscontroller.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -96,7 +96,7 @@ class AccessController {
if (!participant) {
LOG.debug(method, 'No participant');
LOG.exit(method);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
return Promise.resolve();
}

Expand All @@ -109,7 +109,7 @@ class AccessController {
if (!aclManager.getAclFile()) {
LOG.debug(method, 'No ACL file');
LOG.exit(method);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
return Promise.resolve();
}

Expand Down Expand Up @@ -138,7 +138,7 @@ class AccessController {
// If a ACL rule permitted the action, return.
if (result) {
LOG.exit(method);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
return;
}

Expand All @@ -148,7 +148,7 @@ class AccessController {
})
.catch((error) => {
LOG.error(method, error);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
throw error;
});
}
Expand Down
4 changes: 2 additions & 2 deletions packages/composer-runtime/lib/engine.queries.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -41,7 +41,7 @@ class EngineQueries {

if (args.length !== 3) {
LOG.error(method, 'Invalid arguments', args);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
throw new Error(util.format('Invalid arguments "%j" to function "%s", expecting "%j"', args, 'executeQuery', ['queryType', 'query', 'parameters']));
}

Expand Down Expand Up @@ -95,7 +95,7 @@ class EngineQueries {
})
.then((objects) => {
LOG.exit(method, objects);
LOG.debug('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
LOG.verbose('@PERF ' + method, 'Total (ms) duration: ' + (Date.now() - t0).toFixed(2));
return objects;
});

Expand Down
Loading

0 comments on commit a9be602

Please sign in to comment.