HTTP slow query logs provide basic information about requests that do not meet your Apdex score. This information includes the host, URL, status code, response time, and the time of the event.
However, this information is often insufficient for developers to locate the specific time-consuming operations within a request. The slow tracing analysis module helps developers resolve slow HTTP request issues more effectively.
This feature is now available. We welcome your feedback.
Usage
I. Upgrade @alicloud/agenthub
First, run the following command to reinstall the @alicloud/agenthub module and upgrade its agentx dependency to the latest version:
npm install @alicloud/agenthubTo use the tracing feature, ensure that the agentx version of the globally installed agenthub is >= 1.10.1.
After the installation is complete, restart agenthub as usual for the changes to take effect.
II. Use @alicloud/opentracing for instrumentation
Currently, developers must use the @alicloud/opentracing module to manually add instrumentation before and after time-consuming operations, such as asynchronous invocations, throughout an HTTP request. This process connects the entire call chain. The usage of this module is described in the following sections.
1. Installation
npm install @alicloud/opentracing2. Usage
Public class: Tracer(name[, option][, reporter])
a. Parameters
name (String): The name of the tracer.
option (Object): Optional.
limit (Number): The maximum number of data records that can be written to disk per minute. This parameter prevents disk overflow that can be caused by writing many logs when many exceptions occur.
logger (Object): The log handle. It must implement at least the info, log, warn, and error methods. By default, the console is used.
reporter (Object): A custom send method. It must implement the report method, which accepts a span as an input parameter.
b. Member method: startSpan(spanName[, option])
spanName (String): The name of the span. It is used to mark the asynchronous invocation associated with this span.
option (Object): Optional.
childOf (Object): The parent span instance of the current span.
Return value (Object): Returns an instance of the built-in Span class.
Built-in class: Span
a. Member method: setTag(tag, value)
tag (String): The tag name. You can customize this name. It is usually obtained from opentracing.Tags, which defines common trace information keys such as host, url, and statusCode.
value (String): The value that corresponds to the tag name.
b. Member method: log(key, value)
key (String): A custom log key.
value (String): A custom log value.
c. Member method: finish(req)
req (Object): The request object of the HTTP request.
Complete example
The following is a complete example of using instrumentation in Express application middleware. This example simulates concurrent and sequential time-consuming asynchronous calls.
Note: For a root span to be valid and appear in the console, its tags must include HTTP_METHOD, HTTP_URL, and HTTP_STATUS_CODE. Otherwise, the server-side filters out the span.
'use strict';
const express = require('express');
const app = express();
const opentracing = require('@alicloud/opentracing');
const tracer = new opentracing.Tracer('Test Trace');
// Simulate a time-consuming asynchronous operation.
function delay(time, req) {
let child = tracer.startSpan('Submodule 1: Random concurrent delay', { childOf: req.parentSpan });
child.setTag('timeout', time);
child.log({ state: 'timer1' });
return new Promise((resolve, reject) => {
setTimeout(() => {
resolve();
child.finish(req);
}, time);
});
}
// Before all middleware, start a root span to record the hostname, method, and URL.
app.use(function (req, res, next) {
req.parentSpan = tracer.startSpan('Root module');
req.parentSpan.setTag(opentracing.Tags.PEER_HOSTNAME, req.hostname);
req.parentSpan.setTag(opentracing.Tags.HTTP_METHOD, req.method.toUpperCase());
req.parentSpan.setTag(opentracing.Tags.HTTP_URL, req.url);
next();
res.once('finish', () => {
req.parentSpan.setTag(opentracing.Tags.HTTP_STATUS_CODE, res.statusCode);
req.parentSpan.finish(req);
});
});
// Simulate concurrent, time-consuming asynchronous operations.
app.use(function (req, res, next) {
Promise.all([
delay(Math.random() * 10 * 1000, req),
delay(Math.random() * 10 * 1000, req)
]).then(() => next());
});
// Continue to simulate a sequential, 3s time-consuming asynchronous operation.
app.use(function (req, res, next) {
let child = tracer.startSpan('Submodule 2: 3s delay', { childOf: req.parentSpan });
child.setTag('timeout', '3s');
child.log({ state: 'timer2' });
// 3s call
setTimeout(() => {
child.finish(req);
next()
}, 3000);
});
// Respond to the page.
app.get('*', function (req, res) {
res.send('Hello Node.js Performance Platform!');
});
app.listen(3000);In a browser, make a request to http://localhost:3000/delay. After about one minute, the following information appears in the corresponding tab of the console:
Click the string or the bar in the Request Information column to view the details of the recorded request. For example, for the random delay, the current delay in milliseconds and the timer name are recorded using a tag and a log, respectively. If you click the bar for Submodule 1 in the Request Information column, the following content is displayed:
