diff options
author | Tom Zanussi <tom.zanussi@linux.intel.com> | 2018-01-15 21:51:40 -0500 |
---|---|---|
committer | Steven Rostedt (VMware) <rostedt@goodmis.org> | 2018-03-10 16:05:50 -0500 |
commit | dc4e2801d400b0346fb281ce9cf010d611e2243c (patch) | |
tree | c02ee22ac10758d4cf4d23fd9ed85934cdf0c80f /kernel/trace/ring_buffer.c | |
parent | 00b4145298aeb05a2d110117ed18148cb21ebd14 (diff) |
ring-buffer: Redefine the unimplemented RINGBUF_TYPE_TIME_STAMP
RINGBUF_TYPE_TIME_STAMP is defined but not used, and from what I can
gather was reserved for something like an absolute timestamp feature
for the ring buffer, if not a complete replacement of the current
time_delta scheme.
This code redefines RINGBUF_TYPE_TIME_STAMP to implement absolute time
stamps. Another way to look at it is that it essentially forces
extended time_deltas for all events.
The motivation for doing this is to enable time_deltas that aren't
dependent on previous events in the ring buffer, making it feasible to
use the ring_buffer_event timetamps in a more random-access way, for
purposes other than serial event printing.
To set/reset this mode, use tracing_set_timestamp_abs() from the
previous interface patch.
Link: http://lkml.kernel.org/r/477b362dba1ce7fab9889a1a8e885a62c472f041.1516069914.git.tom.zanussi@linux.intel.com
Signed-off-by: Tom Zanussi <tom.zanussi@linux.intel.com>
Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
Diffstat (limited to 'kernel/trace/ring_buffer.c')
-rw-r--r-- | kernel/trace/ring_buffer.c | 104 |
1 files changed, 76 insertions, 28 deletions
diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c index 2a03e069bbc6..33073cdebb26 100644 --- a/kernel/trace/ring_buffer.c +++ b/kernel/trace/ring_buffer.c | |||
@@ -41,6 +41,8 @@ int ring_buffer_print_entry_header(struct trace_seq *s) | |||
41 | RINGBUF_TYPE_PADDING); | 41 | RINGBUF_TYPE_PADDING); |
42 | trace_seq_printf(s, "\ttime_extend : type == %d\n", | 42 | trace_seq_printf(s, "\ttime_extend : type == %d\n", |
43 | RINGBUF_TYPE_TIME_EXTEND); | 43 | RINGBUF_TYPE_TIME_EXTEND); |
44 | trace_seq_printf(s, "\ttime_stamp : type == %d\n", | ||
45 | RINGBUF_TYPE_TIME_STAMP); | ||
44 | trace_seq_printf(s, "\tdata max type_len == %d\n", | 46 | trace_seq_printf(s, "\tdata max type_len == %d\n", |
45 | RINGBUF_TYPE_DATA_TYPE_LEN_MAX); | 47 | RINGBUF_TYPE_DATA_TYPE_LEN_MAX); |
46 | 48 | ||
@@ -140,12 +142,15 @@ int ring_buffer_print_entry_header(struct trace_seq *s) | |||
140 | 142 | ||
141 | enum { | 143 | enum { |
142 | RB_LEN_TIME_EXTEND = 8, | 144 | RB_LEN_TIME_EXTEND = 8, |
143 | RB_LEN_TIME_STAMP = 16, | 145 | RB_LEN_TIME_STAMP = 8, |
144 | }; | 146 | }; |
145 | 147 | ||
146 | #define skip_time_extend(event) \ | 148 | #define skip_time_extend(event) \ |
147 | ((struct ring_buffer_event *)((char *)event + RB_LEN_TIME_EXTEND)) | 149 | ((struct ring_buffer_event *)((char *)event + RB_LEN_TIME_EXTEND)) |
148 | 150 | ||
151 | #define extended_time(event) \ | ||
152 | (event->type_len >= RINGBUF_TYPE_TIME_EXTEND) | ||
153 | |||
149 | static inline int rb_null_event(struct ring_buffer_event *event) | 154 | static inline int rb_null_event(struct ring_buffer_event *event) |
150 | { | 155 | { |
151 | return event->type_len == RINGBUF_TYPE_PADDING && !event->time_delta; | 156 | return event->type_len == RINGBUF_TYPE_PADDING && !event->time_delta; |
@@ -209,7 +214,7 @@ rb_event_ts_length(struct ring_buffer_event *event) | |||
209 | { | 214 | { |
210 | unsigned len = 0; | 215 | unsigned len = 0; |
211 | 216 | ||
212 | if (event->type_len == RINGBUF_TYPE_TIME_EXTEND) { | 217 | if (extended_time(event)) { |
213 | /* time extends include the data event after it */ | 218 | /* time extends include the data event after it */ |
214 | len = RB_LEN_TIME_EXTEND; | 219 | len = RB_LEN_TIME_EXTEND; |
215 | event = skip_time_extend(event); | 220 | event = skip_time_extend(event); |
@@ -231,7 +236,7 @@ unsigned ring_buffer_event_length(struct ring_buffer_event *event) | |||
231 | { | 236 | { |
232 | unsigned length; | 237 | unsigned length; |
233 | 238 | ||
234 | if (event->type_len == RINGBUF_TYPE_TIME_EXTEND) | 239 | if (extended_time(event)) |
235 | event = skip_time_extend(event); | 240 | event = skip_time_extend(event); |
236 | 241 | ||
237 | length = rb_event_length(event); | 242 | length = rb_event_length(event); |
@@ -248,7 +253,7 @@ EXPORT_SYMBOL_GPL(ring_buffer_event_length); | |||
248 | static __always_inline void * | 253 | static __always_inline void * |
249 | rb_event_data(struct ring_buffer_event *event) | 254 | rb_event_data(struct ring_buffer_event *event) |
250 | { | 255 | { |
251 | if (event->type_len == RINGBUF_TYPE_TIME_EXTEND) | 256 | if (extended_time(event)) |
252 | event = skip_time_extend(event); | 257 | event = skip_time_extend(event); |
253 | BUG_ON(event->type_len > RINGBUF_TYPE_DATA_TYPE_LEN_MAX); | 258 | BUG_ON(event->type_len > RINGBUF_TYPE_DATA_TYPE_LEN_MAX); |
254 | /* If length is in len field, then array[0] has the data */ | 259 | /* If length is in len field, then array[0] has the data */ |
@@ -275,6 +280,27 @@ EXPORT_SYMBOL_GPL(ring_buffer_event_data); | |||
275 | #define TS_MASK ((1ULL << TS_SHIFT) - 1) | 280 | #define TS_MASK ((1ULL << TS_SHIFT) - 1) |
276 | #define TS_DELTA_TEST (~TS_MASK) | 281 | #define TS_DELTA_TEST (~TS_MASK) |
277 | 282 | ||
283 | /** | ||
284 | * ring_buffer_event_time_stamp - return the event's extended timestamp | ||
285 | * @event: the event to get the timestamp of | ||
286 | * | ||
287 | * Returns the extended timestamp associated with a data event. | ||
288 | * An extended time_stamp is a 64-bit timestamp represented | ||
289 | * internally in a special way that makes the best use of space | ||
290 | * contained within a ring buffer event. This function decodes | ||
291 | * it and maps it to a straight u64 value. | ||
292 | */ | ||
293 | u64 ring_buffer_event_time_stamp(struct ring_buffer_event *event) | ||
294 | { | ||
295 | u64 ts; | ||
296 | |||
297 | ts = event->array[0]; | ||
298 | ts <<= TS_SHIFT; | ||
299 | ts += event->time_delta; | ||
300 | |||
301 | return ts; | ||
302 | } | ||
303 | |||
278 | /* Flag when events were overwritten */ | 304 | /* Flag when events were overwritten */ |
279 | #define RB_MISSED_EVENTS (1 << 31) | 305 | #define RB_MISSED_EVENTS (1 << 31) |
280 | /* Missed count stored at end */ | 306 | /* Missed count stored at end */ |
@@ -2217,12 +2243,15 @@ rb_move_tail(struct ring_buffer_per_cpu *cpu_buffer, | |||
2217 | 2243 | ||
2218 | /* Slow path, do not inline */ | 2244 | /* Slow path, do not inline */ |
2219 | static noinline struct ring_buffer_event * | 2245 | static noinline struct ring_buffer_event * |
2220 | rb_add_time_stamp(struct ring_buffer_event *event, u64 delta) | 2246 | rb_add_time_stamp(struct ring_buffer_event *event, u64 delta, bool abs) |
2221 | { | 2247 | { |
2222 | event->type_len = RINGBUF_TYPE_TIME_EXTEND; | 2248 | if (abs) |
2249 | event->type_len = RINGBUF_TYPE_TIME_STAMP; | ||
2250 | else | ||
2251 | event->type_len = RINGBUF_TYPE_TIME_EXTEND; | ||
2223 | 2252 | ||
2224 | /* Not the first event on the page? */ | 2253 | /* Not the first event on the page, or not delta? */ |
2225 | if (rb_event_index(event)) { | 2254 | if (abs || rb_event_index(event)) { |
2226 | event->time_delta = delta & TS_MASK; | 2255 | event->time_delta = delta & TS_MASK; |
2227 | event->array[0] = delta >> TS_SHIFT; | 2256 | event->array[0] = delta >> TS_SHIFT; |
2228 | } else { | 2257 | } else { |
@@ -2265,7 +2294,9 @@ rb_update_event(struct ring_buffer_per_cpu *cpu_buffer, | |||
2265 | * add it to the start of the resevered space. | 2294 | * add it to the start of the resevered space. |
2266 | */ | 2295 | */ |
2267 | if (unlikely(info->add_timestamp)) { | 2296 | if (unlikely(info->add_timestamp)) { |
2268 | event = rb_add_time_stamp(event, delta); | 2297 | bool abs = ring_buffer_time_stamp_abs(cpu_buffer->buffer); |
2298 | |||
2299 | event = rb_add_time_stamp(event, info->delta, abs); | ||
2269 | length -= RB_LEN_TIME_EXTEND; | 2300 | length -= RB_LEN_TIME_EXTEND; |
2270 | delta = 0; | 2301 | delta = 0; |
2271 | } | 2302 | } |
@@ -2453,7 +2484,7 @@ static __always_inline void rb_end_commit(struct ring_buffer_per_cpu *cpu_buffer | |||
2453 | 2484 | ||
2454 | static inline void rb_event_discard(struct ring_buffer_event *event) | 2485 | static inline void rb_event_discard(struct ring_buffer_event *event) |
2455 | { | 2486 | { |
2456 | if (event->type_len == RINGBUF_TYPE_TIME_EXTEND) | 2487 | if (extended_time(event)) |
2457 | event = skip_time_extend(event); | 2488 | event = skip_time_extend(event); |
2458 | 2489 | ||
2459 | /* array[0] holds the actual length for the discarded event */ | 2490 | /* array[0] holds the actual length for the discarded event */ |
@@ -2497,10 +2528,11 @@ rb_update_write_stamp(struct ring_buffer_per_cpu *cpu_buffer, | |||
2497 | cpu_buffer->write_stamp = | 2528 | cpu_buffer->write_stamp = |
2498 | cpu_buffer->commit_page->page->time_stamp; | 2529 | cpu_buffer->commit_page->page->time_stamp; |
2499 | else if (event->type_len == RINGBUF_TYPE_TIME_EXTEND) { | 2530 | else if (event->type_len == RINGBUF_TYPE_TIME_EXTEND) { |
2500 | delta = event->array[0]; | 2531 | delta = ring_buffer_event_time_stamp(event); |
2501 | delta <<= TS_SHIFT; | ||
2502 | delta += event->time_delta; | ||
2503 | cpu_buffer->write_stamp += delta; | 2532 | cpu_buffer->write_stamp += delta; |
2533 | } else if (event->type_len == RINGBUF_TYPE_TIME_STAMP) { | ||
2534 | delta = ring_buffer_event_time_stamp(event); | ||
2535 | cpu_buffer->write_stamp = delta; | ||
2504 | } else | 2536 | } else |
2505 | cpu_buffer->write_stamp += event->time_delta; | 2537 | cpu_buffer->write_stamp += event->time_delta; |
2506 | } | 2538 | } |
@@ -2680,7 +2712,7 @@ __rb_reserve_next(struct ring_buffer_per_cpu *cpu_buffer, | |||
2680 | * If this is the first commit on the page, then it has the same | 2712 | * If this is the first commit on the page, then it has the same |
2681 | * timestamp as the page itself. | 2713 | * timestamp as the page itself. |
2682 | */ | 2714 | */ |
2683 | if (!tail) | 2715 | if (!tail && !ring_buffer_time_stamp_abs(cpu_buffer->buffer)) |
2684 | info->delta = 0; | 2716 | info->delta = 0; |
2685 | 2717 | ||
2686 | /* See if we shot pass the end of this buffer page */ | 2718 | /* See if we shot pass the end of this buffer page */ |
@@ -2757,8 +2789,11 @@ rb_reserve_next_event(struct ring_buffer *buffer, | |||
2757 | /* make sure this diff is calculated here */ | 2789 | /* make sure this diff is calculated here */ |
2758 | barrier(); | 2790 | barrier(); |
2759 | 2791 | ||
2760 | /* Did the write stamp get updated already? */ | 2792 | if (ring_buffer_time_stamp_abs(buffer)) { |
2761 | if (likely(info.ts >= cpu_buffer->write_stamp)) { | 2793 | info.delta = info.ts; |
2794 | rb_handle_timestamp(cpu_buffer, &info); | ||
2795 | } else /* Did the write stamp get updated already? */ | ||
2796 | if (likely(info.ts >= cpu_buffer->write_stamp)) { | ||
2762 | info.delta = diff; | 2797 | info.delta = diff; |
2763 | if (unlikely(test_time_stamp(info.delta))) | 2798 | if (unlikely(test_time_stamp(info.delta))) |
2764 | rb_handle_timestamp(cpu_buffer, &info); | 2799 | rb_handle_timestamp(cpu_buffer, &info); |
@@ -3440,14 +3475,13 @@ rb_update_read_stamp(struct ring_buffer_per_cpu *cpu_buffer, | |||
3440 | return; | 3475 | return; |
3441 | 3476 | ||
3442 | case RINGBUF_TYPE_TIME_EXTEND: | 3477 | case RINGBUF_TYPE_TIME_EXTEND: |
3443 | delta = event->array[0]; | 3478 | delta = ring_buffer_event_time_stamp(event); |
3444 | delta <<= TS_SHIFT; | ||
3445 | delta += event->time_delta; | ||
3446 | cpu_buffer->read_stamp += delta; | 3479 | cpu_buffer->read_stamp += delta; |
3447 | return; | 3480 | return; |
3448 | 3481 | ||
3449 | case RINGBUF_TYPE_TIME_STAMP: | 3482 | case RINGBUF_TYPE_TIME_STAMP: |
3450 | /* FIXME: not implemented */ | 3483 | delta = ring_buffer_event_time_stamp(event); |
3484 | cpu_buffer->read_stamp = delta; | ||
3451 | return; | 3485 | return; |
3452 | 3486 | ||
3453 | case RINGBUF_TYPE_DATA: | 3487 | case RINGBUF_TYPE_DATA: |
@@ -3471,14 +3505,13 @@ rb_update_iter_read_stamp(struct ring_buffer_iter *iter, | |||
3471 | return; | 3505 | return; |
3472 | 3506 | ||
3473 | case RINGBUF_TYPE_TIME_EXTEND: | 3507 | case RINGBUF_TYPE_TIME_EXTEND: |
3474 | delta = event->array[0]; | 3508 | delta = ring_buffer_event_time_stamp(event); |
3475 | delta <<= TS_SHIFT; | ||
3476 | delta += event->time_delta; | ||
3477 | iter->read_stamp += delta; | 3509 | iter->read_stamp += delta; |
3478 | return; | 3510 | return; |
3479 | 3511 | ||
3480 | case RINGBUF_TYPE_TIME_STAMP: | 3512 | case RINGBUF_TYPE_TIME_STAMP: |
3481 | /* FIXME: not implemented */ | 3513 | delta = ring_buffer_event_time_stamp(event); |
3514 | iter->read_stamp = delta; | ||
3482 | return; | 3515 | return; |
3483 | 3516 | ||
3484 | case RINGBUF_TYPE_DATA: | 3517 | case RINGBUF_TYPE_DATA: |
@@ -3702,6 +3735,8 @@ rb_buffer_peek(struct ring_buffer_per_cpu *cpu_buffer, u64 *ts, | |||
3702 | struct buffer_page *reader; | 3735 | struct buffer_page *reader; |
3703 | int nr_loops = 0; | 3736 | int nr_loops = 0; |
3704 | 3737 | ||
3738 | if (ts) | ||
3739 | *ts = 0; | ||
3705 | again: | 3740 | again: |
3706 | /* | 3741 | /* |
3707 | * We repeat when a time extend is encountered. | 3742 | * We repeat when a time extend is encountered. |
@@ -3738,12 +3773,17 @@ rb_buffer_peek(struct ring_buffer_per_cpu *cpu_buffer, u64 *ts, | |||
3738 | goto again; | 3773 | goto again; |
3739 | 3774 | ||
3740 | case RINGBUF_TYPE_TIME_STAMP: | 3775 | case RINGBUF_TYPE_TIME_STAMP: |
3741 | /* FIXME: not implemented */ | 3776 | if (ts) { |
3777 | *ts = ring_buffer_event_time_stamp(event); | ||
3778 | ring_buffer_normalize_time_stamp(cpu_buffer->buffer, | ||
3779 | cpu_buffer->cpu, ts); | ||
3780 | } | ||
3781 | /* Internal data, OK to advance */ | ||
3742 | rb_advance_reader(cpu_buffer); | 3782 | rb_advance_reader(cpu_buffer); |
3743 | goto again; | 3783 | goto again; |
3744 | 3784 | ||
3745 | case RINGBUF_TYPE_DATA: | 3785 | case RINGBUF_TYPE_DATA: |
3746 | if (ts) { | 3786 | if (ts && !(*ts)) { |
3747 | *ts = cpu_buffer->read_stamp + event->time_delta; | 3787 | *ts = cpu_buffer->read_stamp + event->time_delta; |
3748 | ring_buffer_normalize_time_stamp(cpu_buffer->buffer, | 3788 | ring_buffer_normalize_time_stamp(cpu_buffer->buffer, |
3749 | cpu_buffer->cpu, ts); | 3789 | cpu_buffer->cpu, ts); |
@@ -3768,6 +3808,9 @@ rb_iter_peek(struct ring_buffer_iter *iter, u64 *ts) | |||
3768 | struct ring_buffer_event *event; | 3808 | struct ring_buffer_event *event; |
3769 | int nr_loops = 0; | 3809 | int nr_loops = 0; |
3770 | 3810 | ||
3811 | if (ts) | ||
3812 | *ts = 0; | ||
3813 | |||
3771 | cpu_buffer = iter->cpu_buffer; | 3814 | cpu_buffer = iter->cpu_buffer; |
3772 | buffer = cpu_buffer->buffer; | 3815 | buffer = cpu_buffer->buffer; |
3773 | 3816 | ||
@@ -3820,12 +3863,17 @@ rb_iter_peek(struct ring_buffer_iter *iter, u64 *ts) | |||
3820 | goto again; | 3863 | goto again; |
3821 | 3864 | ||
3822 | case RINGBUF_TYPE_TIME_STAMP: | 3865 | case RINGBUF_TYPE_TIME_STAMP: |
3823 | /* FIXME: not implemented */ | 3866 | if (ts) { |
3867 | *ts = ring_buffer_event_time_stamp(event); | ||
3868 | ring_buffer_normalize_time_stamp(cpu_buffer->buffer, | ||
3869 | cpu_buffer->cpu, ts); | ||
3870 | } | ||
3871 | /* Internal data, OK to advance */ | ||
3824 | rb_advance_iter(iter); | 3872 | rb_advance_iter(iter); |
3825 | goto again; | 3873 | goto again; |
3826 | 3874 | ||
3827 | case RINGBUF_TYPE_DATA: | 3875 | case RINGBUF_TYPE_DATA: |
3828 | if (ts) { | 3876 | if (ts && !(*ts)) { |
3829 | *ts = iter->read_stamp + event->time_delta; | 3877 | *ts = iter->read_stamp + event->time_delta; |
3830 | ring_buffer_normalize_time_stamp(buffer, | 3878 | ring_buffer_normalize_time_stamp(buffer, |
3831 | cpu_buffer->cpu, ts); | 3879 | cpu_buffer->cpu, ts); |