Skip to content

Commit 184c867

Browse files
chris-smithIanTheEngineer
authored andcommitted
Logging Update (#26)
Pull request for issue #20. This is built on #19. * Pulls in bunyan for logging backend. * Exposes various log methods through rosnodejs.log. * Publish logs to /rosout * Logging tests * Adds persistent option for Service Clients
1 parent 4a484f5 commit 184c867

25 files changed

+1192
-416
lines changed

example.js

+19-7
Original file line numberDiff line numberDiff line change
@@ -9,28 +9,40 @@ rosnodejs.initNode('/my_node')
99
// EXP 1) Service Server
1010
let service = rosNode.advertiseService('/set_bool', SetBool,
1111
(req, resp) => {
12-
console.log('Handling request! ' + JSON.stringify(req));
12+
rosnodejs.log.info('Handling request! ' + JSON.stringify(req));
1313
resp.success = !req.data;
1414
resp.message = 'Inverted!';
1515
return true;
1616
});
1717

1818
// EXP 2) Service Client
19-
let serviceClient = rosNode.serviceClient('/set_bool', 'std_srvs/SetBool');
19+
let serviceClient = rosNode.serviceClient('/set_bool', 'std_srvs/SetBool', {persist: true});
2020
rosNode.waitForService(serviceClient.getService(), 2000)
2121
.then((available) => {
2222
if (available) {
2323
const request = new SetBool.Request();
2424
request.data = true;
25-
serviceClient.call(request, (resp) => {
26-
console.log('Service response ' + JSON.stringify(resp));
25+
serviceClient.call(request).then((resp) => {
26+
rosnodejs.log.info('Service response ' + JSON.stringify(resp));
27+
})
28+
.then(() => {
29+
request.data = false;
30+
serviceClient.call(request).then((resp) => {
31+
rosnodejs.log.info('Service response 2 ' + JSON.stringify(resp));
32+
});
33+
})
34+
.then(() => {
35+
let serviceClient2 = rosNode.serviceClient('/set_bool', 'std_srvs/SetBool');
36+
serviceClient2.call(request).then((resp) => {
37+
rosnodejs.log.info('Non persistent response ' + JSON.stringify(resp));
38+
})
2739
});
2840
}
2941
});
3042

3143
// EXP 3) Params
3244
rosNode.setParam('~junk', {'hi': 2}).then(() => {
33-
rosNode.getParam('~junk').then((val) => { console.log('Got Param!!! ' + JSON.stringify(val)); });
45+
rosNode.getParam('~junk').then((val) => { rosnodejs.log.info('Got Param!!! ' + JSON.stringify(val)); });
3446
});
3547

3648
// EXP 4) Publisher
@@ -57,7 +69,7 @@ rosnodejs.initNode('/my_node')
5769
// EXP 5) Subscriber
5870
let sub = rosNode.subscribe('/my_topic', 'std_msgs/String',
5971
(data) => {
60-
console.log('SUB DATA ' + data.data);
72+
rosnodejs.log.info('SUB DATA ' + data.data);
6173
},
6274
{
6375
queueSize: 1,
@@ -66,5 +78,5 @@ rosnodejs.initNode('/my_node')
6678
);
6779
})
6880
.catch((err) => {
69-
console.log(err);
81+
rosnodejs.log.info(err);
7082
});

example2.js

+4-4
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@
33
let rosnodejs = require('./index.js');
44

55
rosnodejs.initNode('/my_node', {
6-
messages: ['std_msgs/String'],
6+
messages: ['std_msgs/String'],
77
services: ['std_srvs/SetBool']
88
}).then((rosNode) => {
99

@@ -31,7 +31,7 @@ rosnodejs.initNode('/my_node', {
3131
if (available) {
3232
const request = new SetBool.Request();
3333
request.data = true;
34-
serviceClient.call(request, (resp) => {
34+
serviceClient.call(request).then((resp) => {
3535
console.log('Service response ' + JSON.stringify(resp));
3636
});
3737
} else {
@@ -56,14 +56,14 @@ rosnodejs.initNode('/my_node', {
5656

5757
// EXP 5) Subscriber
5858
let sub = rosNode.subscribe(
59-
'/my_topic',
59+
'/my_topic',
6060
'std_msgs/String',
6161
(data) => {
6262
console.log('SUB DATA ', data, data.data);
6363
},
6464
{queueSize: 1,
6565
throttleMs: 1000});
66-
66+
6767
let msgStart = 'my message ';
6868
let iter = 0;
6969
setInterval(() => {

index.js

+31-17
Original file line numberDiff line numberDiff line change
@@ -23,16 +23,22 @@ const netUtils = require('./utils/network_utils.js');
2323
const msgUtils = require('./utils/message_utils.js');
2424
const messages = require('./utils/messages.js');
2525
const util = require('util');
26+
const RosLogStream = require('./utils/log/RosLogStream.js');
27+
const ConsoleLogStream = require('./utils/log/ConsoleLogStream.js');
28+
const LogFormatter = require('./utils/log/LogFormatter.js');
29+
const RosNode = require('./lib/RosNode.js');
30+
const NodeHandle = require('./lib/NodeHandle.js');
31+
const Logging = require('./lib/Logging.js');
32+
2633
msgUtils.findMessageFiles();
2734

2835
// these will be modules, they depend on logger which isn't initialized yet
2936
// though so they'll be required later (in initNode)
30-
let logger = null;
31-
let RosNode = null;
32-
let NodeHandle = null;
37+
// let RosNode = null;
38+
// let NodeHandle = null;
3339

3440
// will be initialized through call to initNode
35-
let log = null;
41+
let log = Logging.getLogger();
3642
let rosNode = null;
3743
let firstCheck = true;
3844

@@ -48,12 +54,12 @@ function _checkMasterHelper(callback, timeout) {
4854
// else
4955
rosNode.getMasterUri()
5056
.then((resp) => {
51-
log.info('Connected to master!');
52-
callback(Rosnodejs.getNodeHandle());
57+
log.infoOnce('Connected to master!');
58+
callback();
5359
})
5460
.catch((err, resp) => {
5561
if (firstCheck) {
56-
log.warn('Unable to connect to master. ' + err);
62+
log.warnOnce('Unable to connect to master. ' + err);
5763
firstCheck = false;
5864
}
5965
_checkMasterHelper(callback, 500);
@@ -121,23 +127,20 @@ let Rosnodejs = {
121127
netUtils.setPortRange(options.portRange);
122128
}
123129

124-
// setup logger
125-
logger = require('./utils/logger.js');
126-
logger.init(options.logger);
127-
log = logger.createLogger();
128-
129-
// require other necessary modules...
130-
RosNode = require('./lib/RosNode.js');
131-
NodeHandle = require('./lib/NodeHandle.js');
132-
133130
// create the ros node. Return a promise that will
134131
// resolve when connection to master is established
135132
let checkMasterTimeout = 0;
136133
rosNode = new RosNode(nodeName, rosMasterUri);
137134

138135
return new Promise((resolve, reject) => {
139136
this.use(options.messages, options.services).then(() => {
140-
_checkMasterHelper(resolve, 0);
137+
138+
const connectedToMasterCallback = () => {
139+
Logging.initializeOptions(this, options.logging);
140+
resolve(this.getNodeHandle());
141+
};
142+
143+
_checkMasterHelper(connectedToMasterCallback, 0);
141144
});
142145
})
143146
.catch((err) => {
@@ -226,6 +229,17 @@ let Rosnodejs = {
226229

227230
get nh() {
228231
return new NodeHandle(rosNode);
232+
},
233+
234+
get log() {
235+
return Logging;
236+
},
237+
238+
get logStreams() {
239+
return {
240+
console: ConsoleLogStream,
241+
ros: RosLogStream
242+
}
229243
}
230244
}
231245

lib/Logging.js

+204
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,204 @@
1+
/*
2+
* Copyright 2016 Rethink Robotics
3+
*
4+
* Copyright 2016 Chris Smith
5+
*
6+
* Licensed under the Apache License, Version 2.0 (the "License");
7+
* you may not use this file except in compliance with the License.
8+
* You may obtain a copy of the License at
9+
* http://www.apache.org/licenses/LICENSE-2.0
10+
*
11+
* Unless required by applicable law or agreed to in writing, software
12+
* distributed under the License is distributed on an "AS IS" BASIS,
13+
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
14+
* See the License for the specific language governing permissions and
15+
* limitations under the License.
16+
*/
17+
18+
'use strict';
19+
const bunyan = require('bunyan');
20+
const Logger = require('../utils/log/Logger.js');
21+
const RosLogStream = require('../utils/log/RosLogStream.js');
22+
const ConsoleLogStream = require('../utils/log/ConsoleLogStream.js');
23+
const LogFormatter = require('../utils/log/LogFormatter.js');
24+
25+
//-----------------------------------------------------------------------
26+
27+
const DEFAULT_LOGGER_NAME = 'ros';
28+
29+
//-----------------------------------------------------------------------
30+
31+
class LoggingManager {
32+
constructor() {
33+
this.loggerMap = {};
34+
35+
// initialize the root logger with a console stream
36+
const rootLoggerOptions = {
37+
name: DEFAULT_LOGGER_NAME,
38+
streams: [{
39+
type: 'raw',
40+
stream: new ConsoleLogStream({formatter: LogFormatter.ROS}),
41+
level: 'info'
42+
}]
43+
}
44+
this.rootLogger = new Logger(rootLoggerOptions);
45+
this._bindRootLoggerMethods();
46+
47+
this.DEFAULT_LOGGER_NAME = DEFAULT_LOGGER_NAME;
48+
}
49+
50+
initializeOptions(rosnodejs, options) {
51+
const nh = rosnodejs.nh;
52+
const defaultOptions = {
53+
streams: [{
54+
type: 'raw',
55+
level: 'info',
56+
stream: new RosLogStream(nh, rosnodejs.require('rosgraph_msgs').msg.Log)
57+
}]
58+
};
59+
if (!options) {
60+
this.initializeOptions(rosnodejs, defaultOptions);
61+
return;
62+
}
63+
// else
64+
65+
// try to set up logging services
66+
try {
67+
rosnodejs.require('roscpp');
68+
const getLoggerSrv = '/' + nh.getNodeName() + '/get_loggers';
69+
const setLoggerSrv = '/' + nh.getNodeName() + '/set_logger_level';
70+
nh.advertiseService(getLoggerSrv, 'roscpp/GetLoggers', this._handleGetLoggers.bind(this))
71+
nh.advertiseService(setLoggerSrv, 'roscpp/SetLoggerLevel', this._handleSetLoggerLevel.bind(this))
72+
}
73+
catch (err) {
74+
this.rootLogger.warn('Unable to setup ros logging services');
75+
}
76+
77+
// setup desired streams
78+
if (options.hasOwnProperty('streams')) {
79+
options.streams.forEach((stream) => {
80+
this.addStream(stream);
81+
});
82+
}
83+
// set desired log level
84+
if (options.hasOwnProperty('level')) {
85+
this.setLevel(options.level);
86+
}
87+
}
88+
89+
generateLogger(options) {
90+
if (!options.hasOwnProperty('name')) {
91+
throw new Error('Unable to generate logger without name');
92+
}
93+
const loggerName = options.name;
94+
95+
// don't regenerate the logger if it exists
96+
if (this.loggerMap.hasOwnProperty(loggerName)) {
97+
return this.loggerMap[loggerName];
98+
}
99+
// else
100+
// generate a child logger from root
101+
let newLogger = this._createChildLogger(loggerName, this.rootLogger, options);
102+
103+
// stash the logger and return it
104+
this.loggerMap[loggerName] = newLogger;
105+
return newLogger;
106+
}
107+
108+
getLogger(loggerName, options) {
109+
if (!loggerName) {
110+
return this.rootLogger;
111+
}
112+
else if (!this.hasLogger(loggerName)) {
113+
options = options || {};
114+
options.name = loggerName;
115+
return this.generateLogger(options);
116+
}
117+
// else
118+
return this.loggerMap[loggerName];
119+
}
120+
121+
hasLogger(loggerName) {
122+
return this.loggerMap.hasOwnProperty(loggerName);
123+
}
124+
125+
removeLogger(loggerName) {
126+
if (loggerName !== DEFAULT_LOGGER_NAME) {
127+
delete this.loggerMap[loggerName];
128+
}
129+
}
130+
131+
getLoggers() {
132+
return Object.keys(loggerMap);
133+
}
134+
135+
setLevel(level) {
136+
this._forEachLogger((logger) => logger.setLevel(level), true);
137+
}
138+
139+
addStream(stream) {
140+
this._forEachLogger((logger) => logger.addStream(stream), true);
141+
}
142+
143+
clearStreams() {
144+
this._forEachLogger((logger) => logger.clearStreams(), true);
145+
}
146+
147+
_handleGetLoggers(req, resp) {
148+
this._forEachLogger((logger) => {
149+
resp.loggers.push({
150+
name: logger.getName(),
151+
level: bunyan.nameFromLevel[logger.getLevel()]
152+
});
153+
}, true);
154+
155+
return true;
156+
}
157+
158+
_handleSetLoggerLevel(req, resp) {
159+
if (!this.hasLogger(req.logger)) {
160+
return false;
161+
}
162+
// else
163+
const logger = this.getLogger(req.logger);
164+
logger.setLevel(req.level);
165+
166+
return true;
167+
}
168+
169+
_bindRootLoggerMethods() {
170+
const rawMethods = ['trace', 'debug', 'info', 'warn', 'error', 'fatal'];
171+
let methods = [];
172+
rawMethods.forEach((method) => methods.push(method));
173+
rawMethods.forEach((method) => methods.push(method + 'Throttle'));
174+
rawMethods.forEach((method) => methods.push(method + 'Once'));
175+
methods.forEach((method) => {
176+
this[method] = this.rootLogger[method].bind(this.rootLogger);
177+
});
178+
}
179+
180+
_forEachLogger(perLoggerCallback, includeRoot) {
181+
if (includeRoot) {
182+
perLoggerCallback(this.rootLogger);
183+
}
184+
Object.keys(this.loggerMap).forEach((loggerName) => {
185+
perLoggerCallback(this.loggerMap[loggerName])
186+
});
187+
}
188+
189+
_createChildLogger(childLoggerName, parentLogger, options) {
190+
// setup options
191+
options = options || {};
192+
options.name = childLoggerName;
193+
options.$parent = parentLogger._logger;
194+
195+
// create logger
196+
const childLogger = new Logger(options);
197+
198+
// cache in map
199+
this.loggerMap[childLoggerName] = childLogger;
200+
return childLogger;
201+
};
202+
};
203+
204+
module.exports = new LoggingManager();

0 commit comments

Comments
 (0)