Tracing
Real-time inspection
Introduction
When working with a system like VerneMQ sometimes when troubleshooting it would be nice to know what a client is actually sending and receiving and what VerneMQ is doing with this information. For this purpose VerneMQ has a built-in tracing mechanism which is safe to use in production settings as there is very little overhead in running the tracer and has built-in protection mechanisms to stop traces that produce too much information.
Tracing clients
To trace a client the following command is available:
See the available flags by calling vmq-admin trace client --help
.
A typical trace could look like the following:
In this particular trace a trace was started for the client with client-id client
. At first no clients are connected to the node where the trace has been started, but a little later the client connects and we see the trace come alive. The strange identifier <7616.3443.1>
is called a process identifier and is the identifier of the process in which the trace happened - this isn't relevant unless one wants to correlate the trace with log entries where process identifiers are also logged. Besides the process identifier there are some lines with MQTT SEND
and MQTT RECV
which are to be understood from the perspective of the broker. In the above trace this means that first the broker receives a CONNECT
frame and replies with a CONNACK
frame. Each MQTT event is annotated with the data from the MQTT frame to give as much detail and insight as possible.
Notice the auth_on_register
call between CONNECT
and CONNACK
which is the authentication plugin hook being called to authenticate the client. In this case the hook returned ok
which means the client was successfully authenticated.
Likewise notice the auth_on_subscribe
call between the SUBSCRIBE
and SUBACK
frames which is plugin hook used to authorize if this particular subscription should be allowed or not. In this case the subscription was authorized.
Trace options
The client trace command has additional options as shown by vmq-admin trace client --help
. Those are hopefully self-explaining:
A convenient tool is the ts
(timestamp) tool which is available on many systems. If the trace output is piped to this command each line is prefixed with a timestamp:
ts | sudo vmq-admin trace client client-id=tester
It is currently not possible to start multiple traces from multiple shells, or trace multiple ClientIDs.
Stopping a Trace from another shell
If you loose access to your shell from where you started a trace, you might need to stop that trace before you can spawn a new one. Your attempt to spawn a second trace will result in the following output:
You can stop a running trace using the stop_all
command from a second shell. This will log a message to the other shell telling that session it's being externally terminated. The calling shell will silently return and be available for a new trace.
Last updated