Subject: Re: [RFC PATCH v3 3/3] trace2: write overload message to sentinel files

From: Josh Steadmon <[email-masked]>
Date: Thu, 19 Sep 2019 15:47:33 -0700

On 2019.09.19 14:23, Jeff Hostetler wrote:
> 
> 
> On 9/16/2019 2:20 PM, Josh Steadmon wrote:
> > On 2019.09.16 10:11, Jeff Hostetler wrote:
> > > 
> > > 
> > > On 9/16/2019 8:07 AM, Derrick Stolee wrote:
> > > > On 9/13/2019 8:26 PM, Josh Steadmon wrote:
> > > > > Add a new "overload" event type for trace2 event destinations. Write
> > > > > this event into the sentinel file created by the trace2.maxFiles
> > > > > feature. Bump up the event format version since we've added a new event
> > > > > type.
> > > > > 
> > > > > Writing this message into the sentinel file is useful for tracking how
> > > > > often the overload protection feature is triggered in practice.
> > > > 
> > > > Putting meaningful data into the sentinel file is valuable. It's
> > > > important to know a bit about when and why this happened. A user
> > > > would be able to inspect the modified time, and the directory info
> > > > you include is unnecessary. The data you include is only for the
> > > > log aggregator to keep valuable data around overloads.
> > > > > +`"overload"`::
> > > > > +	This event is created in a sentinel file if we are overloading a target
> > > > > +	trace directory (see the trace2.maxFiles config option).
> > > > > ++
> > > > > +------------
> > > > > +{
> > > > > +	"event":"overload",
> > > > > +	...
> > > > > +	"dir":"/trace/target/dir/", # The configured trace2 target directory
> > > > > +	"evt":"2",		    # EVENT format version
> > > > > +}
> > > > That said, do we really need to resort to a new event format and
> > > > event type? Could we instead use the "data" event with a key
> > > > "overload" and put the target dir in the value?
> > > > 
> > > > Thanks,
> > > > -Stolee
> > > > 
> > > 
> > > If I understand the code here, the overload event/message is
> > > only written to the sentinel file -- it is not written to a
> > > regular trace2 log file, so regular log file consumers will
> > > never see this event, right?
> > 
> > Well, I guess it's hard to define what is a "regular log file consumer".
> > In our case, our collection system will treat sentinel files like any
> > other trace file, so it's useful to have it match the expected trace
> > format.
> > 
> > At least for our use, we don't want the sentinel files treated
> > specially, because we want the log collection system to just do its
> > thing and remove the file after processing, which lets Git know that
> > it's ok to start writing traces again.
> > 
> > > That message could be in any format, right?  And you could write
> > > as much or as little data into the sentinel file as you want.
> > 
> > To me it seems that it would be less surprising on the users' side if
> > any data written to the sentinel file matches the format of the
> > requested traces. If I have an automated process that's reading JSON
> > from a directory full of files, I don't want to have to add a special
> > case where one file might have perf-format data (or vice versa).
> > 
> > > There's no compelling reason to extend the existing trace2 format
> > > to have a new message type, so I'm not seeing a reason to add the
> > > event-type nor to increment the version number.
> > > 
> > > The existing trace2 formats and messages/event-types are defined
> > > and driven by the Trace2 API calls presented to upper layers
> > > (consumers of the public trace2_*() functions and macros defined
> > > in trace2.h).  This overload event doesn't fit that model.
> > 
> > Yeah, I did feel like this might be overkill. Do you think Stolee's
> > suggestion to use a "data" event instead would be acceptable?
> > 
> > > I think it'd be better to just directly write() a message -- in
> > > plain-text or JSON or whatever -- in tr2_create_sentinel() and
> > > not try to piggy-back on the existing format machinery in the
> > > tr2_tgt_*.c files.
> > 
> > I had a version that did this originally, but I don't really like having
> > an unexpected special case where we just write a static JSON string. It
> > feels like an ugly corner case, and would be surprising to users, IMO.
> > But if everyone thinks this is a better approach, I suppose I could just
> > add a switch statement in tr2_create_sentinel() that looks at the
> > sysenv_var field of the tr2_dst.
> > 
> 
> 
> You make some good points.  I suppose it would be good to be able
> to parse the overload file using the same reader/scheme as the
> other events.  Well, at least for the JSON format; the other formats
> don't really matter for your purposes anyway.
> 
> I am concerned that the new "overload" event will be the only event
> in the file and therefore replace the "version" event in those files.
> That is, we'll break the invariant that all JSON files begin with a
> "version" event that containing the event version string.  That is,
> in the current proposal, the format becomes:
> 
>     v2 ::= <overload> | <<v1>>
>     v1 ::= <version> <start> ... <atexit>
> 
> V1 readers were promised that the first event in the file would
> always be a <version> event.

Ah interesting, I wasn't aware of this. Thanks for clarifying. I do see
that there's a recommendation that trace2_initialize() should be called
"as early as possible", but perhaps I should add a note to the docs?

> And that they can dispatch on the
> version.evt field.  V1 readers won't recognize the <overload> event
> and they won't know to look at the overload.evt field.  That might
> cause V1 parsers to throw a harder error than a simpler version
> mismatch.
> 
> Just using a "data" event also feels wrong for the same reasons.
> At that point in tr2_create_sentinel(), a new "data" event would
> just give us:
> 
>     V2 ::= <data key="overload", value="true"> | <<v1>>
>     v1 ::= <version> <start> ... <atexit>
> 
> Having said that I wonder if it would be better to have
> tr2_create_sentinel() just set a flag (and leave the fd open).
> And then either add the new event as:
> 
>     V2 ::= <version evt=2> <overload dir=path, max=n> | <<v1>>
> 
> or just add a column to the <version> event (and go ahead and
> let the overload file be a full trace2 log from the command):
> 
>     V1 ::= <version evt=1, [overload=true]> <start> ... <atexit>
> 
> Does that make sense??

Yeah, that seems reasonable. We're already adding one more file to the
target directory, so we might as well include the traces from this run.

However, you're still keeping evt=1 here; do we make any promises about
fields within events being constant in a particular event version? After
scanning api-trace2.txt, I don't see any explicit description of what
may or may not change within a version, and the idea that we might add
new fields would be surprising at least to me. I'm fine either way so
long as it's documented. Would a section like the following in
api-trace2.txt be acceptable?

"""
Adding new fields to events does not require a change in the EVT.
Removing fields, or adding or removing event types does require an
increment to the EVT.
"""

> Jeff

Thanks for the review,
Josh