<div dir="ltr">Thanks Ryan, I think I have a clearer picture now.<div><br></div><div>So, indeed, I think you only need a only a light vmod and a log analyzer.</div><div><br></div><div>If I get what's happening, you need a vmod call in vcl_recv to create a trace if it doesn't exist yet, and in vcl_backend_fetch to create a span.</div><div>Then, you can simply look at the log, and you'll have all the meta data you need (including IP, ports, timings and such).</div><div><br></div><div>You may want a specific function to set the component name per-request, but that can easily be done through std.log, so I wouldn't worry about it at first.</div><div><br></div><div>Am I completely off, or is that at least remotely sensible?</div><div><br></div></div><div class="gmail_extra"><br clear="all"><div><div class="gmail_signature" data-smartmail="gmail_signature"><div dir="ltr"><div>-- <br></div>Guillaume Quintard<br></div></div></div>
<br><div class="gmail_quote">On Thu, May 11, 2017 at 10:20 PM, Ryan Burn <span dir="ltr"><<a href="mailto:rnickb731@gmail.com" target="_blank">rnickb731@gmail.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">Sure. The intention with OpenTracing is to provide a common API that<br>
can be used to instrument frameworks and libraries. What happens when,<br>
for example, a span is created or its context injected into a request<br>
header isn’t specified by the standard. It’s up to the particular<br>
tracing implementation used (e.g. LightStep, Zipkin, Jaeger, etc) to<br>
decide what specifically to do.<br>
<br>
So, if a user wants to enable varnish for OpenTracing, I’d expect them<br>
do something like the following in their VCL:<br>
<br>
###<br>
# This is distributed as part of the varnish-opentracing project. It<br>
imports a varnish module<br>
# that exposes VCL functions to interact with the C++ OpenTracing API<br>
# <a href="https://github.com/opentracing/opentracing-cpp" rel="noreferrer" target="_blank">https://github.com/<wbr>opentracing/opentracing-cpp</a><br>
# and adds commands to the VCL built-in subroutines so that the<br>
module’s functions will<br>
# be invoked when certain events occur.<br>
include “opentracing.vcl”;<br>
<br>
<br>
# A user also needs to select a tracing implementation to use. This is<br>
done by importing<br>
# the implementation’s module and initializing the tracer in vcl_init.<br>
For example, if they’re<br>
# using LightStep they might do something like this<br>
import lightstep;<br>
<br>
sub vcl_init {<br>
lightstep.collector_host(“…”);<br>
lightstep.collector_port(“…”);<br>
lightstep.init_tracer();<br>
}<br>
<br>
<br>
# Tracing is then explicitly turned on for a particular request with<br>
logic in the vcl_recv subroutine.<br>
# This means that a span will be created for the request and any<br>
backend requests that result from it.<br>
# The trace’s context will also be propagated into the backend request<br>
headers, so that any tracing done<br>
# by the backend server can be linked to it.<br>
sub vcl_recv {<br>
# This turns on tracing for all requests.<br>
opentracing.trace_request();<br>
}<br>
###<br>
<br>
<br>
Though all the pieces aren’t together, I have an example set up here<br>
<br>
<a href="https://github.com/rnburn/varnish-opentracing/blob/master/example/library/varnish/library.vcl" rel="noreferrer" target="_blank">https://github.com/rnburn/<wbr>varnish-opentracing/blob/<wbr>master/example/library/<wbr>varnish/library.vcl</a><br>
<br>
To go back to the questions:<br>
<span class=""><br>
- what data do you inject, and how do you create it?<br>
</span>You would be injecting a list of key-value pairs that represent the<br>
context of the active span<br>
(<a href="https://github.com/opentracing/specification/blob/master/specification.md#spancontext" rel="noreferrer" target="_blank">https://github.com/<wbr>opentracing/specification/<wbr>blob/master/specification.md#<wbr>spancontext</a>).<br>
Specifically what that means is up to the tracing implementation, but<br>
it would look something like this:<br>
<br>
<br>
'ot-tracer-traceid': 'f84de504f0287bbc' // An ID used to<br>
identify the Trace.<br>
'ot-tracer-spanid': 'e34088878e7f0ce8' // An ID used to identify<br>
the active span within the Trace.<br>
'ot-tracer-sampled': 'true' // Heuristic<br>
used by the Tracer<br>
<span class=""><br>
- what do you need to know about the req/resp/bereq/beresp?<br>
</span>Knowing whether the request resulted in an error is pretty important<br>
to record. Other data usually added<br>
are the URI, http method, ip addresses of the client, server, and<br>
backend servers. Some of the guidelines on what to include are<br>
documented here:<br>
<br>
<a href="https://github.com/opentracing/specification/blob/master/semantic_conventions.md" rel="noreferrer" target="_blank">https://github.com/<wbr>opentracing/specification/<wbr>blob/master/semantic_<wbr>conventions.md</a><br>
<br>
<br>
An example might make this clearer. This shows the breakdown of a<br>
trace representing the action of a user submitting a profile form:<br>
<br>
<a href="https://github.com/rnburn/nginx-opentracing/blob/master/doc/data/nginx-upload-trace5.png" rel="noreferrer" target="_blank">https://github.com/rnburn/<wbr>nginx-opentracing/blob/master/<wbr>doc/data/nginx-upload-trace5.<wbr>png</a><br>
<br>
The server (described in more detail here<br>
<a href="https://github.com/rnburn/nginx-opentracing/blob/master/doc/Tutorial.md" rel="noreferrer" target="_blank">https://github.com/rnburn/<wbr>nginx-opentracing/blob/master/<wbr>doc/Tutorial.md</a>)<br>
uses nginx as a reverse proxy in front of Node.js servers that update<br>
a database and perform image manipulation. You can see spans created<br>
on the nginx side to track the duration of the request and how long it<br>
passes through various location blocks as well as spans created from<br>
the Node.js server to represent the database activity and image<br>
manipulation. Injecting context into the request headers is what<br>
allows the spans to be linked together so that the entire trace can be<br>
formed.<br>
<div class="HOEnZb"><div class="h5"><br>
On Thu, May 11, 2017 at 9:38 PM, Guillaume Quintard<br>
<<a href="mailto:guillaume@varnish-software.com">guillaume@varnish-software.<wbr>com</a>> wrote:<br>
> you can put anything in the priv field of the task, but the issue is that<br>
> you have to put that data in there, meaning a call to your vmod from the<br>
> vcl.<br>
><br>
> the VUT.dispatch_f function isn't to be called from a vmod, and I don't<br>
> think you need to.<br>
><br>
> Maybe it's time to take a step back, can you fill us in the whole workflow,<br>
> notably:<br>
> - what data do you inject, and how do you create it?<br>
> - what do you need to know about the req/resp/bereq/beresp?<br>
><br>
> I almost have the feeling that this could be solved through pure vcl+shell.<br>
><br>
> --<br>
> Guillaume Quintard<br>
><br>
> On Thu, May 11, 2017 at 5:33 PM, Ryan Burn <<a href="mailto:rnickb731@gmail.com">rnickb731@gmail.com</a>> wrote:<br>
>><br>
>> From the free function, is there any way to get the status code or<br>
>> other properties of the request? I tried using VRT_r_obj_status with a<br>
>> stored reference to the context, but that doesn't seem to work since<br>
>> some of the request's resources have already been reclaimed:<br>
>><br>
>><br>
>> <a href="https://github.com/rnburn/varnish-opentracing/blob/master/opentracing/src/trace.cpp#L22" rel="noreferrer" target="_blank">https://github.com/rnburn/<wbr>varnish-opentracing/blob/<wbr>master/opentracing/src/trace.<wbr>cpp#L22</a><br>
>><br>
>> Is there any other place something like the status would be stored?<br>
>><br>
>><br>
>> On Mon, May 8, 2017 at 11:13 AM, Reza Naghibi <<a href="mailto:reza@varnish-software.com">reza@varnish-software.com</a>><br>
>> wrote:<br>
>> > Sorry, email misfire.<br>
>> ><br>
>> > You can do this in a VMOD via PRIV_TASK:<br>
>> ><br>
>> ><br>
>> > <a href="https://varnish-cache.org/docs/trunk/reference/vmod.html#private-pointers" rel="noreferrer" target="_blank">https://varnish-cache.org/<wbr>docs/trunk/reference/vmod.<wbr>html#private-pointers</a><br>
>> ><br>
>> > It might make sense to track this stuff in some kind of struct, in which<br>
>> > case, put it into *priv and then register a *free callback. Otherwise,<br>
>> > just<br>
>> > put a dummy value into the *priv. *free will get called after the<br>
>> > request is<br>
>> > done and you can put your custom code in there.<br>
>> ><br>
>> > --<br>
>> > Reza Naghibi<br>
>> > Varnish Software<br>
>> ><br>
>> > On Mon, May 8, 2017 at 11:10 AM, Reza Naghibi<br>
>> > <<a href="mailto:reza@varnish-software.com">reza@varnish-software.com</a>><br>
>> > wrote:<br>
>> >><br>
>> >> You can do this in a VMOD via PRIV_TASK:<br>
>> >><br>
>> >><br>
>> >> --<br>
>> >> Reza Naghibi<br>
>> >> Varnish Software<br>
>> >><br>
>> >> On Fri, May 5, 2017 at 10:15 PM, Ryan Burn <<a href="mailto:rnickb731@gmail.com">rnickb731@gmail.com</a>> wrote:<br>
>> >>><br>
>> >>> Hello,<br>
>> >>> From VCL, is it possible to execute code that runs after a request has<br>
>> >>> been processed?<br>
>> >>><br>
>> >>> I'm looking into writing a module that enables Varnish for distributed<br>
>> >>> tracing using the OpenTracing project [<a href="http://opentracing.io" rel="noreferrer" target="_blank">opentracing.io</a>]. This requires<br>
>> >>> invoking code at the beginning of a request to start a span and insert<br>
>> >>> tracing context into the request's headers and invoking code after a<br>
>> >>> request's been processed to finish the span and measure how long it<br>
>> >>> took to process.<br>
>> >>><br>
>> >>> I recently did a similar project for nginx<br>
>> >>> [<a href="http://github.com/rnburn/nginx-opentracing" rel="noreferrer" target="_blank">github.com/rnburn/nginx-<wbr>opentracing</a>]. Nginx provides an<br>
>> >>> NGX_HTTP_LOG_PHASE [<a href="http://www.nginxguts.com/2011/01/phases/" rel="noreferrer" target="_blank">www.nginxguts.com/2011/01/<wbr>phases/</a>] that allows you<br>
>> >>> to set up handlers run after requests are serviced. Can anything<br>
>> >>> equivalent be done using VCL?<br>
>> >>><br>
>> >>> I image you could accomplish this by subscribing and regularly reading<br>
>> >>> from Varnish's shared memory log, but I'd much rather do it directly<br>
>> >>> if possible.<br>
>> >>><br>
>> >>> Thanks, Ryan<br>
>> >>><br>
>> >>> ______________________________<wbr>_________________<br>
>> >>> varnish-misc mailing list<br>
>> >>> <a href="mailto:varnish-misc@varnish-cache.org">varnish-misc@varnish-cache.org</a><br>
>> >>> <a href="https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc" rel="noreferrer" target="_blank">https://www.varnish-cache.org/<wbr>lists/mailman/listinfo/<wbr>varnish-misc</a><br>
>> >><br>
>> >><br>
>> ><br>
>><br>
>> ______________________________<wbr>_________________<br>
>> varnish-misc mailing list<br>
>> <a href="mailto:varnish-misc@varnish-cache.org">varnish-misc@varnish-cache.org</a><br>
>> <a href="https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc" rel="noreferrer" target="_blank">https://www.varnish-cache.org/<wbr>lists/mailman/listinfo/<wbr>varnish-misc</a><br>
><br>
><br>
</div></div></blockquote></div><br></div>