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