Thanks for your notice Conrad Yes, this is for the New Relic PHP agent, which requires the X-Request-Start to be in microseconds according to:
https://docs.newrelic.com/docs/apm/other-features/request-queueing/configuring-request-queue-reporting#php Yes, after you mentioned it in %Ts, accept_date is in %ms too: case LOG_FMT_MS: // %ms ... ret = utoa_pad((unsigned int)s->logs.accept_date.tv_usec/1000, tmplog, 4); On Mon, Aug 10, 2015 at 12:40 PM, Conrad Hoffmann <con...@soundcloud.com> wrote: > Hey Jose, > > to save you some of the pain I just went through, I would like to add the > following: > > %Ts does not neccessarily give you the time of the processing of the > request, which is what you would want for the typical X-Request-Start > header (are you using NewRelic or a similar service?). This is very hard to > deduce from the documentation, but as far as I can tell it is in fact: > > - the time of the accept() call for the connection when this is the first > request on this connection (which is usually acceptable, but might not > be sometimes) > - something like the end time of the previous request for any subsequent > requests on that connection. > > Thus, if you have long-lived connections that are not constantly churning > out requests, the value of %Ts might significantly deviate from what you > might expect. Maybe Willy can shed some light on when exactly the value of > %Ts is set, but I encourage you do a small test before trusting it (I used > a simple telnet session that I pasted some requests into, with a pause in > between). > > In the end I resorted to calling date(), which only has second resolution > but is at least never off by more than a second. > > Hope that helps, > Conrad > > On 08/10/2015 06:24 PM, Jose Nunez wrote: > > Hi Willy, > > > > thanks for your answer, it works perfectly, thanks! > > > > Jose > > > > On Sun, Aug 9, 2015 at 4:55 AM, Willy Tarreau <w...@1wt.eu> wrote: > > > >> Hi Jose, > >> > >> On Fri, Aug 07, 2015 at 01:28:13PM -0400, Jose Nunez wrote: > >>> Hi, > >>> > >>> I need to express something similar to this: > >>> > >>> http-request set-header X-REQUEST-START t=%[Ts]%[ms]000 > >>> > >>> (to append three "0"s at the end of the timestamp with milliseconds). > >>> > >>> I have tried with other ways to append the three "0"s at the end: > >>> > >>> http-request set-header X-REQUEST-START t=%Ts%[ms]\x30\x30\x30 > >>> > >>> and > >>> > >>> http-request set-header X-REQUEST-START t=%Ts%ms\x30\x30\x30 > >>> > >>> and no avail either. > >> > >> You've met the limits of the log format which is not a language and > >> which requires some delimiters to be detected. Unfortunately it doesn't > >> have any delimiter which doesn't appear in the output. I found a way to > >> abuse it using %[] to mark a new word (since %[] detects the end of the > >> current block using the closing bracket). Using just "%[]" emits a > warning > >> and does exactly what you want. A cleaner method in 1.6 consists in > >> emitting > >> an empty string as a delimitor : %[str()]. In 1.5, there is no str(), > but > >> you can use %[env()] which will retrieve the contents of the environment > >> variable with no name, it doesn't exist so it returns an empty string. > Yes > >> I know that's ugly, but the log format has gone far beyond its design > goals > >> already! > >> > >> Thus it will give you this in 1.5 : > >> > >> http-request set-header X-REQUEST-START t=%Ts%ms%[env()]000 > >> > >> In 1.6 you can also do that : > >> > >> http-request set-header X-REQUEST-START t=%Ts%ms%[str(000)] > >> > >> Also, please note that what you're doing above only works because %ms is > >> left-padded with zeroes. I'm not seeing this documented anywhere though. > >> > >> Willy > >> > >> > > > > -- > Conrad Hoffmann > Traffic Engineer > > SoundCloud Ltd. | Rheinsberger Str. 76/77, 10115 Berlin, Germany > > Managing Director: Alexander Ljung | Incorporated in England & Wales > with Company No. 6343600 | Local Branch Office | AG Charlottenburg | > HRB 110657B >
