Skip to content

Commit 341ac85

Browse files
MarckKyurishkuro
authored andcommitted
Finish nodejs tutorial (yurishkuro#6)
1 parent f462a7d commit 341ac85

File tree

7 files changed

+436
-184
lines changed

7 files changed

+436
-184
lines changed

nodejs/README.md

+26-30
Original file line numberDiff line numberDiff line change
@@ -2,55 +2,52 @@
22

33
## Installing
44

5-
The tutorials are using CNCF Jaeger (https://github.com/jaegertracing/jaeger) as the tracing backend,
5+
The tutorials are using CNCF Jaeger (https://github.com/jaegertracing/jaeger) as the tracing backend,
66
[see here](../README.md) how to install it in a Docker image.
77

8-
Install the dependencies:
8+
First clone the [opentracing-tutorial](https://github.com/yurishkuro/opentracing-tutorial), then install the dependencies:
99

1010
```
1111
cd opentracing-tutorial/nodejs
1212
npm install
1313
```
1414

15-
The rest of the commands in the Node.js tutorials should be executed relative to this directory.
15+
The rest of the commands in the Node.js tutorials should be executed relative to this `nodejs` directory.
1616

1717
## Under construction
1818

1919
This tutorial is currently incomplete. You can try following the tutorials in the other languages
2020
and adapt them to Node.js, as all the same features are available in the OpenTracing API for Javascript
21-
(https://github.com/opentracing/opentracing-javascript). Use the following code to initialize Jaeger tracer:
21+
(https://github.com/opentracing/opentracing-javascript). Use the following code to initialize Jaeger tracer:
2222

2323
```javascript
24-
var initJaegerTracer = require('jaeger-client').initTracer;
24+
var initJaegerTracer = require("jaeger-client").initTracer;
2525

2626
function initTracer(serviceName) {
27-
var config = {
28-
'serviceName': serviceName,
29-
'sampler': {
30-
'type': 'const',
31-
'param': 1
32-
},
33-
'reporter': {
34-
'logSpans': true
35-
}
36-
};
37-
var options = {
38-
'logger': {
39-
'info': function logInfo(msg) {
40-
console.log('INFO ', msg);
41-
},
42-
'error': function logError(msg) {
43-
console.log('ERROR', msg)
44-
}
45-
}
46-
};
47-
return initJaegerTracer(config, options);
27+
var config = {
28+
serviceName: serviceName,
29+
sampler: {
30+
type: "const",
31+
param: 1,
32+
},
33+
reporter: {
34+
logSpans: true,
35+
},
36+
};
37+
var options = {
38+
logger: {
39+
info: function logInfo(msg) {
40+
console.log("INFO ", msg);
41+
},
42+
error: function logError(msg) {
43+
console.log("ERROR", msg);
44+
},
45+
},
46+
};
47+
return initJaegerTracer(config, options);
4848
}
4949
```
5050

51-
Note that Lesson 1 has a solution provided, which you can use to bootstrap your work for the other lessons.
52-
53-
<!--
5451
## Lessons
5552

5653
* [Lesson 01 - Hello World](./lesson01)
@@ -70,4 +67,3 @@ Note that Lesson 1 has a solution provided, which you can use to bootstrap your
7067
* Use baggage to pass data through the call graph
7168
* [Extra Credit](./extracredit)
7269
* Use existing open source instrumentation
73-
-->

nodejs/lesson01/README.md

+184-19
Original file line numberDiff line numberDiff line change
@@ -1,8 +1,3 @@
1-
**NOTE**
2-
3-
This README is currently incomplete / unfinished. Please refer to respective README in tutorials for one of the other languages
4-
5-
61
# Lesson 1 - Hello World
72

83
## Objectives
@@ -17,29 +12,199 @@ Learn how to:
1712

1813
### A simple Hello-World program
1914

15+
Let's create a simple Node program `lesson01/exercise/hello.js` that takes an argument and prints "Hello, {arg}!".
16+
17+
```
18+
mkdir -p lesson01/exercise
19+
touch lesson01/exercise/hello.js
20+
```
21+
22+
In lesson01/exercise/hello.js:
23+
24+
```javascript
25+
const assert = require("assert");
26+
27+
const sayHello = helloTo => {
28+
const helloStr = `Hello, ${helloTo}!`;
29+
console.log(helloStr);
30+
};
31+
32+
assert(process.argv.length == 3, "Expecting one argument");
33+
const helloTo = process.argv[2];
34+
sayHello(helloTo);
35+
```
2036

2137
Run it:
38+
39+
```
40+
$ node lesson01/exercise/hello.js Bryan
41+
Hello, Bryan!
2242
```
23-
npm install
24-
node lesson01/solution/hello.js Peter
25-
INFO Initializing Jaeger Tracer with CompositeReporter and ConstSampler
26-
Hello app listening on port 8080
2743

44+
### Create a trace
45+
46+
A trace is a [directed acyclic graph](https://en.wikipedia.org/wiki/Directed_acyclic_graph) of spans. A span is a logical representation of some work done in your application.
47+
Each span has these minimum attributes: an operation name, a start time, and a finish time.
48+
49+
Let's create a trace that consists of just a single span. To do that we need an instance of the `opentracing.Tracer`.
50+
We can use a global instance return by `new opentracing.Tracer()`.
51+
52+
```javascript
53+
const opentracing = require("opentracing");
54+
55+
const tracer = new opentracing.Tracer();
56+
57+
const sayHello = helloTo => {
58+
const span = tracer.startSpan("say-hello");
59+
const helloStr = `Hello, ${helloTo}!`;
60+
console.log(helloStr);
61+
span.finish();
62+
};
2863
```
2964

30-
Run the following curl command a few times:
65+
We are using the following basic features of the OpenTracing API:
66+
67+
* a `tracer` instance is used to start new spans via the `startSpan` function
68+
* each `span` is given an _operation name_, `"say-hello"` in this case
69+
* each `span` must be finished by calling its `finish()` function
70+
* the start and end timestamps of the span will be captured automatically by the tracer implementation
71+
72+
If we run this program, we will see no difference, and no traces in the tracing UI.
73+
That's because the variable `new opentracing.Tracer()` points to a no-op tracer by default.
3174

75+
### Initialize a real tracer
76+
77+
Let's create an instance of a real tracer, such as Jaeger (https://github.com/jaegertracing/jaeger-client-node).
78+
79+
```javascript
80+
const initJaegerTracer = require("jaeger-client").initTracer;
81+
82+
function initTracer(serviceName) {
83+
const config = {
84+
serviceName: serviceName,
85+
sampler: {
86+
type: "const",
87+
param: 1,
88+
},
89+
reporter: {
90+
logSpans: true,
91+
},
92+
};
93+
const options = {
94+
logger: {
95+
info(msg) {
96+
console.log("INFO ", msg);
97+
},
98+
error(msg) {
99+
console.log("ERROR", msg);
100+
},
101+
},
102+
};
103+
return initJaegerTracer(config, options);
104+
}
32105
```
33-
curl localhost:8080
106+
107+
To use this instance, let's replace `new opentracing.Tracer()` with `initTracer(...)`:
108+
109+
```javascript
110+
const tracer = initTracer("hello-world");
34111
```
35112

36-
You should see something below on the console for the client app:
113+
Note that we are passing a string `"hello-world"` to the init method. It is used to mark all spans emitted by
114+
the tracer as originating from a `hello-world` service.
115+
116+
There's one more thing we need to do. Jaeger Tracer is primarily designed for long-running server processes, so it has an internal buffer of spans that is flushed by a background thread. Since our program exists immediately,
117+
it may not have time to flush the spans to Jaeger backend. Let's add the following to the end of `hello.js`:
37118

119+
```javascript
120+
tracer.close(() => process.exit());
38121
```
39-
Hello, Peter!
40-
INFO Reporting span 6d8e165388a35fb5:6d8e165388a35fb5:0:1
41-
Hello, Peter!
42-
INFO Reporting span 48b662d422dfcc86:48b662d422dfcc86:0:1
43-
Hello, Peter!
44-
INFO Reporting span c0e45d92229168c5:c0e45d92229168c5:0:1
45-
```
122+
123+
If we run the program now, we should see a span logged:
124+
125+
```
126+
$ node lesson01/exercise/hello.js Bryan
127+
INFO Initializing Jaeger Tracer with CompositeReporter and ConstSampler
128+
Hello, Bryan!
129+
INFO Reporting span d42d649b3ba9f0f3:d42d649b3ba9f0f3:0:1
130+
```
131+
132+
If you have Jaeger backend running, you should be able to see the trace in the UI.
133+
134+
### Annotate the Trace with Tags and Logs
135+
136+
Right now the trace we created is very basic. If we call our program with argument `Susan`
137+
instead of `Bryan`, the resulting traces will be nearly identical. It would be nice if we could
138+
capture the program arguments in the traces to distinguish them.
139+
140+
One naive way is to use the string `"Hello, Bryan!"` as the _operation name_ of the span, instead of `"say-hello"`.
141+
However, such practice is highly discouraged in distributed tracing, because the operation name is meant to
142+
represent a _class of spans_, rather than a unique instance. For example, in Jaeger UI you can select the
143+
operation name from a dropdown when searching for traces. It would be very bad user experience if we ran the
144+
program to say hello to a 1000 people and the dropdown then contained 1000 entries. Another reason for choosing
145+
more general operation names is to allow the tracing systems to do aggregations. For example, Jaeger tracer
146+
has an option of emitting metrics for all the traffic going through the application. Having a unique
147+
operation name for each span would make the metrics useless.
148+
149+
The recommended solution is to annotate spans with tags or logs. A _tag_ is a key-value pair that provides
150+
certain metadata about the span. A _log_ is similar to a regular log statement, it contains
151+
a timestamp and some data, but it is associated with the span from which it was logged.
152+
153+
When should we use tags vs. logs? The tags are meant to describe attributes of the span that apply
154+
to the whole duration of the span. For example, if a span represents an HTTP request, then the URL of the
155+
request should be recorded as a tag because it does not make sense to think of the URL as something
156+
that's only relevant at different points in time on the span. On the other hand, if the server responded
157+
with a redirect URL, logging it would make more sense since there is a clear timestamp associated with such
158+
event. The OpenTracing Specification provides guidelines called [Semantic Conventions](https://github.com/opentracing/specification/blob/master/semantic_conventions.md)
159+
for recommended tags and log fields.
160+
161+
#### Using Tags
162+
163+
In the case of `hello Bryan`, the string "Bryan" is a good candidate for a span tag, since it applies
164+
to the whole span and not to a particular moment in time. We can record it like this:
165+
166+
```javascript
167+
const span = tracer.startSpan("say-hello");
168+
span.setTag("hello-to", helloTo);
169+
```
170+
171+
#### Using Logs
172+
173+
Our hello program is so simple that it's difficult to find a relevant example of a log, but let's try.
174+
Right now we're formatting the `helloStr` and then printing it. Both of these operations take
175+
time, so we can log their completion:
176+
177+
```javascript
178+
const helloStr = `Hello, ${helloTo}!`;
179+
span.log({
180+
event: "string-format",
181+
value: helloStr,
182+
});
183+
184+
console.log(helloStr);
185+
span.log({ event: "print-string" });
186+
```
187+
188+
The log statements might look a bit strange if you have not previously worked with a structured logging API.
189+
Rather than formatting a log message into a single string that is easy for humans to read, structured
190+
logging APIs encourage you to separate bits and pieces of that message into key-value pairs that can be
191+
automatically processed by log aggregation systems. The idea comes from the realization that today most
192+
logs are processed by machines rather than humans. Just [google "structured-logging"](https://www.google.com/search?q=structured-logging) for many articles on this topic.
193+
194+
The OpenTracing API for JavaScript exposes a structured logging API method `log` that takes a dictionary, or hash,
195+
of key-value pairs.
196+
197+
The OpenTracing Specification also recommends all log statements to contain an `event` field that
198+
describes the overall event being logged, with other attributes of the event provided as additional fields.
199+
200+
If you run the program with these changes, then find the trace in the UI and expand its span (by clicking on it),
201+
you will be able to see the tags and logs.
202+
203+
## Conclusion
204+
205+
The complete program can be found in the [solution](./solution) directory.
206+
207+
We moved the `initTracer`
208+
helper function into its own module so that we can reuse it in the other lessons with a require statement `require("../../lib/tracing")`.
209+
210+
Next lesson: [Context and Tracing Functions](../lesson02).

nodejs/lesson01/solution/hello.js

+20-29
Original file line numberDiff line numberDiff line change
@@ -1,33 +1,24 @@
1-
'use strict';
2-
3-
const assert = require('assert');
4-
const initTracer = require('../../lib/tracing').initTracer;
5-
6-
function sayHello(helloTo) {
7-
var span = tracer.startSpan('say-hello');
8-
span.setTag('hello-to', helloTo);
9-
10-
var helloStr = `Hello, ${helloTo}!`;
11-
span.log({
12-
'event': 'string-format',
13-
'value': helloStr
14-
});
15-
16-
console.log(helloStr);
17-
18-
span.log({'event': 'print-string'})
19-
span.finish();
20-
}
21-
22-
assert.ok(process.argv.length == 3, 'expecting one argument');
23-
1+
const assert = require("assert");
2+
const { initTracer } = require("../../lib/tracing");
3+
4+
const tracer = initTracer("hello-world");
5+
6+
const sayHello = helloTo => {
7+
const span = tracer.startSpan("say-hello");
8+
span.setTag("hello-to", helloTo);
9+
const helloStr = `Hello, ${helloTo}!`;
10+
span.log({
11+
event: "string-format",
12+
value: helloStr,
13+
});
14+
console.log(helloStr);
15+
span.log({ event: "print-string" });
16+
span.finish();
17+
};
18+
19+
assert(process.argv.length == 3, "Expecting one argument");
2420
const helloTo = process.argv[2];
2521

26-
const tracer = initTracer('hello-world');
27-
2822
sayHello(helloTo);
2923

30-
//wait for udp message sent out
31-
setTimeout( e => {tracer.close();}, 12000);
32-
33-
24+
tracer.close(() => process.exit());

0 commit comments

Comments
 (0)