Add tracing activity and tracing section API
authorPhilippe Proulx <eeppeliteloop@gmail.com>
Sat, 19 Nov 2016 19:00:14 +0000 (14:00 -0500)
committerPhilippe Proulx <eeppeliteloop@gmail.com>
Sat, 19 Nov 2016 19:00:14 +0000 (14:00 -0500)
The new barectf_is_tracing_enabled() function allows the instrumented
program to enable or disable tracing for a specific barectf context.
This is a thread-safe API, in that it only sets a member of the context
to 0 or 1. Disabling the tracing activity does not guarantee, however,
that the current packet or back-end is not currently being altered. See
the next paragraph about this.

The new barectf_is_in_tracing_section() function allows the instrumented
program to know if its tracing thread is currently in a barectf section
or not. barectf_is_in_tracing_section_ptr() returns a volatile pointer
to this same information.

Both functions can be used together to implement a snapshot action for a
given platform, something like:

1. The instrumented thread calls the barectf tracing functions during
   its execution. When a packet is closed, the platform appends it to a
   ring buffer, overwriting the oldest recorded one if there's no space
   left. This is called a flight recorder mode.
2. The controller (another thread of the instrumented program, or an
   external host) recognizes a trigger where we would only need the
   latest data to analyze the situation. Therefore tracing must be
   stopped, because we don't want the current ring buffer packets to be
   overwritten anymore.
3. The controller disables tracing. It is safe to call
   barectf_is_tracing_enabled(ctx, 0) from another thread.
4. When barectf_is_tracing_enabled(ctx, 0) is called, the barectf
   tracing function currently being executed still needs to finish. At
   this point it could still alter the current packet. Therefore the
   controller waits until barectf_is_in_tracing_section() is 0.
5. Once barectf_is_in_tracing_section() returns 0, it won't return 1
   until barectf_is_tracing_enabled(ctx, 1) is called again, so it is
   safe to read the ring buffer, and also to read the current packet.

Signed-off-by: Philippe Proulx <eeppeliteloop@gmail.com>
barectf/gen.py
barectf/templates.py

index 55b8edb82171da3a4574c97ab2da709a6f8a374e..694f3e722fe64e4ffd2d54cc84735e3f9ab9050c 100644 (file)
@@ -559,7 +559,15 @@ class CCodeGenerator:
 
     def _generate_func_serialize_event_proto(self, stream, event):
         tmpl = templates._FUNC_SERIALIZE_EVENT_PROTO_BEGIN
+        clock_ctype = 'const int'
+
+        if stream.event_header_type is not None:
+            if 'timestamp' in stream.event_header_type.fields:
+                field = stream.event_header_type['timestamp']
+                clock_ctype = self._get_first_clock_ctype(field)
+
         self._cg.add_lines(tmpl.format(prefix=self._cfg.prefix,
+                                       clock_ctype=clock_ctype,
                                        sname=stream.name, evname=event.name))
         self._generate_func_trace_proto_params(stream, event)
         tmpl = templates._FUNC_SERIALIZE_EVENT_PROTO_END
@@ -657,13 +665,14 @@ class CCodeGenerator:
         lines = tmpl.format(prefix=self._cfg.prefix)
         self._cg.add_lines(lines)
         self._cg.indent()
+        self._cg.add_empty_line()
 
         if stream.event_header_type is not None:
             t = stream.event_header_type
             exclude_list = ['timestamp', 'id']
             params = self._get_call_event_param_list_from_struct(t, _PREFIX_SEH,
                                                                  exclude_list)
-            tmpl = '_serialize_stream_event_header_{sname}(ctx, {evid}{params});'
+            tmpl = '_serialize_stream_event_header_{sname}(ctx, ts, {evid}{params});'
             self._cg.add_cc_line('stream event header')
             self._cg.add_line(tmpl.format(sname=stream.name, evid=event.id,
                                           params=params))
@@ -694,8 +703,16 @@ class CCodeGenerator:
 
     def _generate_func_serialize_stream_event_header_proto(self, stream):
         tmpl = templates._FUNC_SERIALIZE_STREAM_EVENT_HEADER_PROTO_BEGIN
+        clock_ctype = 'const int'
+
+        if stream.event_header_type is not None:
+            if 'timestamp' in stream.event_header_type.fields:
+                field = stream.event_header_type['timestamp']
+                clock_ctype = self._get_first_clock_ctype(field)
+
         self._cg.add_lines(tmpl.format(prefix=self._cfg.prefix,
-                                       sname=stream.name))
+                                       sname=stream.name,
+                                       clock_ctype=clock_ctype))
 
         if stream.event_header_type is not None:
             exclude_list = [
@@ -727,17 +744,6 @@ class CCodeGenerator:
         lines = tmpl.format(prefix=self._cfg.prefix)
         self._cg.add_lines(lines)
         self._cg.indent()
-
-        if stream.event_header_type is not None:
-            if 'timestamp' in stream.event_header_type.fields:
-                timestamp = stream.event_header_type.fields['timestamp']
-                ts_ctype = self._get_int_ctype(timestamp)
-                clock = timestamp.property_mappings[0].object
-                clock_name = clock.name
-                clock_ctype = clock.return_ctype
-                tmpl = '{} ts = ctx->cbs.{}_clock_get_value(ctx->data);'
-                self._cg.add_line(tmpl.format(clock_ctype, clock_name))
-
         self._cg.add_empty_line()
         func = self._generate_func_serialize_event_from_entity
 
@@ -750,6 +756,8 @@ class CCodeGenerator:
                 spec_src['id'] = '({}) event_id'.format(id_t_ctype)
 
             if 'timestamp' in stream.event_header_type.fields:
+                field = stream.event_header_type.fields['timestamp']
+                ts_ctype = self._get_int_ctype(field)
                 spec_src['timestamp'] = '({}) ts'.format(ts_ctype)
 
             func(_PREFIX_SEH, stream.event_header_type, spec_src)
@@ -779,8 +787,18 @@ class CCodeGenerator:
         self._generate_func_trace_proto(stream, event)
         params = self._get_call_event_param_list(stream, event)
         tmpl = templates._FUNC_TRACE_BODY
+        ts_line = ''
+
+        if stream.event_header_type is not None:
+            if 'timestamp' in stream.event_header_type.fields:
+                field = stream.event_header_type.fields['timestamp']
+                ts_line = self._get_ts_line(field)
+
+        if not ts_line:
+            ts_line = '\tconst int ts = 0; /* unused */'
+
         self._cg.add_lines(tmpl.format(sname=stream.name, evname=event.name,
-                                       params=params))
+                                       params=params, ts=ts_line))
 
     def _generate_func_init(self):
         self._reset_per_func_state()
@@ -800,6 +818,27 @@ class CCodeGenerator:
     def _reset_per_func_state(self):
         pass
 
+    def _get_first_clock_ctype(self, field, default='int'):
+        if not field.property_mappings:
+            return 'const {}'.format(default)
+
+        clock = field.property_mappings[0].object
+
+        return 'const {}'.format(clock.return_ctype)
+
+    def _get_ts_line(self, field):
+        if field is None:
+            return ''
+
+        if not field.property_mappings:
+            return ''
+
+        tmpl = '\tconst {} ts = ctx->parent.cbs.{}_clock_get_value(ctx->parent.data);'
+        clock = field.property_mappings[0].object
+        line = tmpl.format(clock.return_ctype, clock.name)
+
+        return line
+
     def _generate_func_open(self, stream):
         def generate_save_offset(name):
             tmpl = 'ctx->off_spc_{} = ctx->parent.at;'.format(name)
@@ -809,28 +848,26 @@ class CCodeGenerator:
         self._reset_per_func_state()
         self._generate_func_open_proto(stream)
         tmpl = templates._FUNC_OPEN_BODY_BEGIN
-        self._cg.add_lines(tmpl)
-        self._cg.indent()
-        tph_type = self._cfg.metadata.trace.packet_header_type
+        ts_line = ''
         spc_type = stream.packet_context_type
 
         if spc_type is not None and 'timestamp_begin' in spc_type.fields:
             field = spc_type.fields['timestamp_begin']
-            tmpl = '{} ts = ctx->parent.cbs.{}_clock_get_value(ctx->parent.data);'
-            clock = field.property_mappings[0].object
-            clock_ctype = clock.return_ctype
-            clock_name = clock.name
-            self._cg.add_line(tmpl.format(clock_ctype, clock_name))
-            self._cg.add_empty_line()
+            ts_line = self._get_ts_line(field)
 
+        lines = tmpl.format(ts=ts_line)
+        self._cg.add_lines(lines)
+        self._cg.indent()
         self._cg.add_cc_line('do not open a packet that is already open')
         self._cg.add_line('if (ctx->parent.packet_is_open) {')
         self._cg.indent()
+        self._cg.add_line('ctx->parent.in_tracing_section = saved_in_tracing_section;')
         self._cg.add_line('return;')
         self._cg.unindent()
         self._cg.add_line('}')
         self._cg.add_empty_line()
         self._cg.add_line('ctx->parent.at = 0;')
+        tph_type = self._cfg.metadata.trace.packet_header_type
 
         if tph_type is not None:
             self._cg.add_empty_line()
@@ -931,23 +968,20 @@ class CCodeGenerator:
         self._reset_per_func_state()
         self._generate_func_close_proto(stream)
         tmpl = templates._FUNC_CLOSE_BODY_BEGIN
-        self._cg.add_lines(tmpl)
-        self._cg.indent()
+        ts_line = ''
         spc_type = stream.packet_context_type
 
-        if spc_type is not None:
-            if 'timestamp_end' in spc_type.fields:
-                tmpl = '{} ts = ctx->parent.cbs.{}_clock_get_value(ctx->parent.data);'
-                field = spc_type.fields['timestamp_end']
-                clock = field.property_mappings[0].object
-                clock_ctype = clock.return_ctype
-                clock_name = clock.name
-                self._cg.add_line(tmpl.format(clock_ctype, clock_name))
-                self._cg.add_empty_line()
+        if spc_type is not None and 'timestamp_end' in spc_type.fields:
+            field = spc_type.fields['timestamp_end']
+            ts_line = self._get_ts_line(field)
 
+        lines = tmpl.format(ts=ts_line)
+        self._cg.add_lines(lines)
+        self._cg.indent()
         self._cg.add_cc_line('do not close a packet that is not open')
         self._cg.add_line('if (!ctx->parent.packet_is_open) {')
         self._cg.indent()
+        self._cg.add_line('ctx->parent.in_tracing_section = saved_in_tracing_section;')
         self._cg.add_line('return;')
         self._cg.unindent()
         self._cg.add_line('}')
index 6dc52cea3cb9ea6e644cf878d5cfa2ac89cf1bbb..696a9ddb338797e827c46d609bbbc11065b08822 100644 (file)
@@ -68,6 +68,12 @@ struct {prefix}ctx {{
 
        /* current packet is opened */
        int packet_is_open;
+
+       /* in tracing code */
+       volatile int in_tracing_section;
+
+       /* tracing is enabled */
+       volatile int is_tracing_enabled;
 }};'''
 
 
@@ -101,6 +107,8 @@ _FUNC_INIT_BODY = '''{{
        ctx->at = 0;
        ctx->events_discarded = 0;
        ctx->packet_is_open = 0;
+       ctx->in_tracing_section = 0;
+       ctx->is_tracing_enabled = 1;
 }}'''
 
 
@@ -112,7 +120,33 @@ void {prefix}{sname}_open_packet(
 _FUNC_OPEN_PROTO_END = ')'
 
 
-_FUNC_OPEN_BODY_BEGIN = '{'
+_FUNC_OPEN_BODY_BEGIN = '''{{
+{ts}
+       const int saved_in_tracing_section = ctx->parent.in_tracing_section;
+
+       /*
+        * This function is either called by a tracing function, or
+        * directly by the platform.
+        *
+        * If it's called by a tracing function, then
+        * ctx->parent.in_tracing_section is 1, so it's safe to open
+        * the packet here (alter the packet), even if tracing was
+        * disabled in the meantime because we're already in a tracing
+        * section (which finishes at the end of the tracing function
+        * call).
+        *
+        * If it's called directly by the platform, then if tracing is
+        * disabled, we don't want to alter the packet, and return
+        * immediately.
+        */
+       if (!ctx->parent.is_tracing_enabled && !saved_in_tracing_section) {{
+               ctx->parent.in_tracing_section = 0;
+               return;
+       }}
+
+       /* we can modify the packet */
+       ctx->parent.in_tracing_section = 1;
+'''
 
 
 _FUNC_OPEN_BODY_END = '''
@@ -120,6 +154,9 @@ _FUNC_OPEN_BODY_END = '''
 
        /* mark current packet as open */
        ctx->parent.packet_is_open = 1;
+
+       /* not tracing anymore */
+       ctx->parent.in_tracing_section = saved_in_tracing_section;
 }'''
 
 
@@ -127,7 +164,33 @@ _FUNC_CLOSE_PROTO = '''/* close packet for stream "{sname}" */
 void {prefix}{sname}_close_packet(struct {prefix}{sname}_ctx *ctx)'''
 
 
-_FUNC_CLOSE_BODY_BEGIN = '{'
+_FUNC_CLOSE_BODY_BEGIN = '''{{
+{ts}
+       const int saved_in_tracing_section = ctx->parent.in_tracing_section;
+
+       /*
+        * This function is either called by a tracing function, or
+        * directly by the platform.
+        *
+        * If it's called by a tracing function, then
+        * ctx->parent.in_tracing_section is 1, so it's safe to close
+        * the packet here (alter the packet), even if tracing was
+        * disabled in the meantime, because we're already in a tracing
+        * section (which finishes at the end of the tracing function
+        * call).
+        *
+        * If it's called directly by the platform, then if tracing is
+        * disabled, we don't want to alter the packet, and return
+        * immediately.
+        */
+       if (!ctx->parent.is_tracing_enabled && !saved_in_tracing_section) {{
+               ctx->parent.in_tracing_section = 0;
+               return;
+       }}
+
+       /* we can modify the packet */
+       ctx->parent.in_tracing_section = 1;
+'''
 
 
 _FUNC_CLOSE_BODY_END = '''
@@ -136,6 +199,9 @@ _FUNC_CLOSE_BODY_END = '''
 
        /* mark packet as closed */
        ctx->parent.packet_is_open = 0;
+
+       /* not tracing anymore */
+       ctx->parent.in_tracing_section = saved_in_tracing_section;
 }'''
 
 
@@ -151,22 +217,34 @@ _FUNC_TRACE_PROTO_END = ')'
 
 
 _FUNC_TRACE_BODY = '''{{
+{ts}
        uint32_t ev_size;
 
+       if (!ctx->parent.is_tracing_enabled) {{
+               return;
+       }}
+
+       /* we can modify the packet */
+       ctx->parent.in_tracing_section = 1;
+
        /* get event size */
        ev_size = _get_event_size_{sname}_{evname}(TO_VOID_PTR(ctx){params});
 
        /* do we have enough space to serialize? */
        if (!_reserve_event_space(TO_VOID_PTR(ctx), ev_size)) {{
                /* no: forget this */
+               ctx->parent.in_tracing_section = 0;
                return;
        }}
 
        /* serialize event */
-       _serialize_event_{sname}_{evname}(TO_VOID_PTR(ctx){params});
+       _serialize_event_{sname}_{evname}(TO_VOID_PTR(ctx), ts{params});
 
        /* commit event */
        _commit_event(TO_VOID_PTR(ctx));
+
+       /* not tracing anymore */
+       ctx->parent.in_tracing_section = 0;
 }}'''
 
 
@@ -188,6 +266,7 @@ _FUNC_GET_EVENT_SIZE_BODY_END = ''' return at - ctx->at;
 
 _FUNC_SERIALIZE_STREAM_EVENT_HEADER_PROTO_BEGIN = '''static void _serialize_stream_event_header_{sname}(
        void *vctx,
+       {clock_ctype} ts,
        uint32_t event_id'''
 
 
@@ -216,7 +295,8 @@ _FUNC_SERIALIZE_STREAM_EVENT_CONTEXT_BODY_END = '}'
 
 
 _FUNC_SERIALIZE_EVENT_PROTO_BEGIN = '''static void _serialize_event_{sname}_{evname}(
-       void *vctx'''
+       void *vctx,
+       {clock_ctype} ts'''
 
 
 _FUNC_SERIALIZE_EVENT_PROTO_END = ')'
@@ -285,7 +365,11 @@ uint32_t {prefix}packet_events_discarded(void *ctx);
 uint8_t *{prefix}packet_buf(void *ctx);
 void {prefix}packet_set_buf(void *ctx, uint8_t *buf, uint32_t buf_size);
 uint32_t {prefix}packet_buf_size(void *ctx);
-int {prefix}packet_is_open(void *ctx);'''
+int {prefix}packet_is_open(void *ctx);
+int {prefix}is_in_tracing_section(void *ctx);
+volatile const int *{prefix}is_in_tracing_section_ptr(void *ctx);
+int {prefix}is_tracing_enabled(void *ctx);
+void {prefix}enable_tracing(void *ctx, int enable);'''
 
 
 _HEADER_END = '''#ifdef __cplusplus
@@ -408,6 +492,26 @@ int {prefix}packet_is_open(void *ctx)
        return FROM_VOID_PTR(struct {prefix}ctx, ctx)->packet_is_open;
 }}
 
+int {prefix}is_in_tracing_section(void *ctx)
+{{
+       return FROM_VOID_PTR(struct {prefix}ctx, ctx)->in_tracing_section;
+}}
+
+volatile const int *{prefix}is_in_tracing_section_ptr(void *ctx)
+{{
+       return &FROM_VOID_PTR(struct {prefix}ctx, ctx)->in_tracing_section;
+}}
+
+int {prefix}is_tracing_enabled(void *ctx)
+{{
+       return FROM_VOID_PTR(struct {prefix}ctx, ctx)->is_tracing_enabled;
+}}
+
+void {prefix}enable_tracing(void *ctx, int enable)
+{{
+       FROM_VOID_PTR(struct {prefix}ctx, ctx)->is_tracing_enabled = enable;
+}}
+
 static
 void _write_cstring(struct {prefix}ctx *ctx, const char *src)
 {{
This page took 0.030147 seconds and 4 git commands to generate.