| Message ID | bab45cb735ad658e6c838a9b2bdb9a8c74b9d179.1568419818.git.steadmon@google.com (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | trace2: don't overload target directories | expand |
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
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? 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. 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. 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. Jeff
On 2019.09.16 08:07, 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? Yeah, that sounds reasonable. Thanks for the suggestion.
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.
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. 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?? Jeff
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
On 9/19/2019 6:47 PM, Josh Steadmon wrote: > 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. > """ Um, good point. Adding fields to an existing event is probably safe -- unless it conveys a more significant change in behavior. Something, for example, that changes the interpretation of existing events or fields would require a version change. I could go either way on this. Perhaps it would be better to just update the version number and add the event. (Sorry to be wishy-washy on this.) json ::= <version evt=1> <<body>> | <version evt=2> [<overload>] [<<body>>] body ::= <start> ... <atexit> That has a bit of a cleaner feel (in hindsight). Jeff
diff --git a/Documentation/technical/api-trace2.txt b/Documentation/technical/api-trace2.txt index 80ffceada0..ef26e47805 100644 --- a/Documentation/technical/api-trace2.txt +++ b/Documentation/technical/api-trace2.txt @@ -128,7 +128,7 @@ yields ------------ $ cat ~/log.event -{"event":"version","sid":"sid":"20190408T191610.507018Z-H9b68c35f-P000059a8","thread":"main","time":"2019-01-16T17:28:42.620713Z","file":"common-main.c","line":38,"evt":"1","exe":"2.20.1.155.g426c96fcdb"} +{"event":"version","sid":"sid":"20190408T191610.507018Z-H9b68c35f-P000059a8","thread":"main","time":"2019-01-16T17:28:42.620713Z","file":"common-main.c","line":38,"evt":"2","exe":"2.20.1.155.g426c96fcdb"} {"event":"start","sid":"20190408T191610.507018Z-H9b68c35f-P000059a8","thread":"main","time":"2019-01-16T17:28:42.621027Z","file":"common-main.c","line":39,"t_abs":0.001173,"argv":["git","version"]} {"event":"cmd_name","sid":"20190408T191610.507018Z-H9b68c35f-P000059a8","thread":"main","time":"2019-01-16T17:28:42.621122Z","file":"git.c","line":432,"name":"version","hierarchy":"version"} {"event":"exit","sid":"20190408T191610.507018Z-H9b68c35f-P000059a8","thread":"main","time":"2019-01-16T17:28:42.621236Z","file":"git.c","line":662,"t_abs":0.001227,"code":0} @@ -610,11 +610,24 @@ only present on the "start" and "atexit" events. { "event":"version", ... - "evt":"1", # EVENT format version + "evt":"2", # EVENT format version "exe":"2.20.1.155.g426c96fcdb" # git version } ------------ +`"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 +} +------------ + `"start"`:: This event contains the complete argv received by main(). + diff --git a/trace2/tr2_dst.c b/trace2/tr2_dst.c index 414053d550..b72be57635 100644 --- a/trace2/tr2_dst.c +++ b/trace2/tr2_dst.c @@ -47,6 +47,38 @@ void tr2_dst_trace_disable(struct tr2_dst *dst) dst->need_close = 0; } +/* + * Create a sentinel file to note that we don't want to create new trace files + * in this location. The form of the sentinel file may vary based on the + * destination type; the default is to create an empty file, but destination + * types can override this by providing an overload_writer function that accepts + * the filename, line number, and target path. + */ +static void tr2_create_sentinel(struct tr2_dst *dst, const char *dir, + const char *sentinel_path) +{ + int fd; + + if (dst->overload_writer) { + fd = open(sentinel_path, O_WRONLY | O_CREAT | O_EXCL, 0666); + if (fd != -1) { + dst->fd = fd; + /* + * I don't think it's particularly useful to include the + * file and line here, but we expect all trace messages + * (at least for "event" destinations) to include them. + * So I'm adding these for consistency's sake. + */ + dst->overload_writer(__FILE__, __LINE__, dir); + tr2_dst_trace_disable(dst); + } + } else + fd = creat(sentinel_path, 0666); + + if (fd != -1) + close(fd); +} + /* * Check to make sure we're not overloading the target directory with too many * files. First get the threshold (if present) from the config or envvar. If @@ -58,7 +90,7 @@ void tr2_dst_trace_disable(struct tr2_dst *dst) * from the target directory; after it removes the sentinel file we'll start * writing traces again. */ -static int tr2_dst_overloaded(const char *tgt_prefix) +static int tr2_dst_overloaded(struct tr2_dst *dst, const char *tgt_prefix) { int file_count = 0, max_files = 0, ret = 0; const char *max_files_var; @@ -97,7 +129,7 @@ static int tr2_dst_overloaded(const char *tgt_prefix) closedir(dirp); if (file_count >= tr2env_max_files) { - creat(sentinel_path.buf, 0666); + tr2_create_sentinel(dst, path.buf, sentinel_path.buf); ret = 1; goto cleanup; } @@ -126,7 +158,7 @@ static int tr2_dst_try_auto_path(struct tr2_dst *dst, const char *tgt_prefix) strbuf_addstr(&path, sid); base_path_len = path.len; - if (tr2_dst_overloaded(tgt_prefix)) { + if (tr2_dst_overloaded(dst, tgt_prefix)) { strbuf_release(&path); if (tr2_dst_want_warning()) warning("trace2: not opening %s trace file due to too " diff --git a/trace2/tr2_dst.h b/trace2/tr2_dst.h index 3adf3bac13..dd09a9541c 100644 --- a/trace2/tr2_dst.h +++ b/trace2/tr2_dst.h @@ -4,11 +4,14 @@ struct strbuf; #include "trace2/tr2_sysenv.h" +typedef void(tr2_dst_overload_writer_t)(const char *file, int line, const char *dir); + struct tr2_dst { enum tr2_sysenv_variable sysenv_var; int fd; unsigned int initialized : 1; unsigned int need_close : 1; + tr2_dst_overload_writer_t *overload_writer; }; /* diff --git a/trace2/tr2_tgt_event.c b/trace2/tr2_tgt_event.c index c2852d1bd2..68cb26fc67 100644 --- a/trace2/tr2_tgt_event.c +++ b/trace2/tr2_tgt_event.c @@ -10,7 +10,9 @@ #include "trace2/tr2_tgt.h" #include "trace2/tr2_tls.h" -static struct tr2_dst tr2dst_event = { TR2_SYSENV_EVENT, 0, 0, 0 }; +static void fn_overload_fl(const char *file, int line, const char *dir); + +static struct tr2_dst tr2dst_event = { TR2_SYSENV_EVENT, 0, 0, 0, fn_overload_fl }; /* * The version number of the JSON data generated by the EVENT target @@ -19,7 +21,7 @@ static struct tr2_dst tr2dst_event = { TR2_SYSENV_EVENT, 0, 0, 0 }; * to update this if you just add another call to one of the existing * TRACE2 API methods. */ -#define TR2_EVENT_VERSION "1" +#define TR2_EVENT_VERSION "2" /* * Region nesting limit for messages written to the event target. @@ -107,6 +109,21 @@ static void event_fmt_prepare(const char *event_name, const char *file, jw_object_intmax(jw, "repo", repo->trace2_repo_id); } +static void fn_overload_fl(const char *file, int line, const char *dir) +{ + const char *event_name = "overload"; + struct json_writer jw = JSON_WRITER_INIT; + + jw_object_begin(&jw, 0); + event_fmt_prepare(event_name, file, line, NULL, &jw); + jw_object_string(&jw, "dir", dir); + jw_object_string(&jw, "evt", TR2_EVENT_VERSION); + jw_end(&jw); + + tr2_dst_write_line(&tr2dst_event, &jw.json); + jw_release(&jw); +} + static void fn_version_fl(const char *file, int line) { const char *event_name = "version"; diff --git a/trace2/tr2_tgt_normal.c b/trace2/tr2_tgt_normal.c index 00b116d797..ffca0d3811 100644 --- a/trace2/tr2_tgt_normal.c +++ b/trace2/tr2_tgt_normal.c @@ -9,7 +9,7 @@ #include "trace2/tr2_tgt.h" #include "trace2/tr2_tls.h" -static struct tr2_dst tr2dst_normal = { TR2_SYSENV_NORMAL, 0, 0, 0 }; +static struct tr2_dst tr2dst_normal = { TR2_SYSENV_NORMAL, 0, 0, 0, NULL }; /* * Use the TR2_SYSENV_NORMAL_BRIEF setting to omit the "<time> <file>:<line>" diff --git a/trace2/tr2_tgt_perf.c b/trace2/tr2_tgt_perf.c index ea0cbbe13e..0a91e8a1f6 100644 --- a/trace2/tr2_tgt_perf.c +++ b/trace2/tr2_tgt_perf.c @@ -11,7 +11,7 @@ #include "trace2/tr2_tgt.h" #include "trace2/tr2_tls.h" -static struct tr2_dst tr2dst_perf = { TR2_SYSENV_PERF, 0, 0, 0 }; +static struct tr2_dst tr2dst_perf = { TR2_SYSENV_PERF, 0, 0, 0, NULL }; /* * Use TR2_SYSENV_PERF_BRIEF to omit the "<time> <file>:<line>"
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. Signed-off-by: Josh Steadmon <steadmon@google.com> --- Documentation/technical/api-trace2.txt | 17 ++++++++++-- trace2/tr2_dst.c | 38 ++++++++++++++++++++++++-- trace2/tr2_dst.h | 3 ++ trace2/tr2_tgt_event.c | 21 ++++++++++++-- trace2/tr2_tgt_normal.c | 2 +- trace2/tr2_tgt_perf.c | 2 +- 6 files changed, 74 insertions(+), 9 deletions(-)