Hi Steven,

Thank you for the patch! Perhaps something to improve:

[auto build test WARNING on tip/perf/core]
[also build test WARNING on linux/master linus/master v5.8-rc2 next-20200625]
[If your patch is applied to the wrong git tree, kindly drop us a note.
And when submitting patch, we suggest to use  as documented in
https://git-scm.com/docs/git-format-patch]

url:    
https://github.com/0day-ci/linux/commits/Steven-Rostedt/ring-buffer-Have-nested-events-still-record-running-time-stamp/20200626-105715
base:   https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git 
bb42b3d39781d7fcd3be7f9f9bf11b6661b5fdf1
config: mips-allyesconfig (attached as .config)
compiler: mips-linux-gcc (GCC) 9.3.0
reproduce (this is a W=1 build):
        wget 
https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O 
~/bin/make.cross
        chmod +x ~/bin/make.cross
        # save the attached .config to linux build tree
        COMPILER_INSTALL_PATH=$HOME/0day COMPILER=gcc-9.3.0 make.cross 
ARCH=mips 

If you fix the issue, kindly add following tag as appropriate
Reported-by: kernel test robot <l...@intel.com>

All warnings (new ones prefixed by >>):

   kernel/trace/ring_buffer.c: In function '__rb_reserve_next':
   kernel/trace/ring_buffer.c:2911:6: warning: unused variable 'delta' 
[-Wunused-variable]
    2911 |  u64 delta, before, after;
         |      ^~~~~
>> kernel/trace/ring_buffer.c:2910:32: warning: variable 'next' set but not 
>> used [-Wunused-but-set-variable]
    2910 |  unsigned long tail, write, w, next;
         |                                ^~~~

vim +/next +2910 kernel/trace/ring_buffer.c

  2903  
  2904  static struct ring_buffer_event *
  2905  __rb_reserve_next(struct ring_buffer_per_cpu *cpu_buffer,
  2906                    struct rb_event_info *info)
  2907  {
  2908          struct ring_buffer_event *event;
  2909          struct buffer_page *tail_page;
> 2910          unsigned long tail, write, w, next;
  2911          u64 delta, before, after;
  2912          bool abs = false;
  2913  
  2914          /* Don't let the compiler play games with cpu_buffer->tail_page 
*/
  2915          tail_page = info->tail_page = READ_ONCE(cpu_buffer->tail_page);
  2916  
  2917   /*A*/  w = local_read(&tail_page->write) & RB_WRITE_MASK;
  2918          barrier();
  2919          before = local64_read(&cpu_buffer->before_stamp);
  2920          after = local64_read(&cpu_buffer->write_stamp);
  2921          barrier();
  2922          info->ts = rb_time_stamp(cpu_buffer->buffer);
  2923  
  2924          if (ring_buffer_time_stamp_abs(cpu_buffer->buffer)) {
  2925                  info->delta = info->ts;
  2926                  abs = true;
  2927          } else {
  2928                  info->delta = info->ts - after;
  2929          }
  2930  
  2931          if (unlikely(test_time_stamp(info->delta)))
  2932                  rb_handle_timestamp(cpu_buffer, info);
  2933  
  2934          /*
  2935           * If interrupting an event time update, we may need an 
absolute timestamp.
  2936           * Don't bother if this is the start of a new page (w == 0).
  2937           */
  2938          if (unlikely(before != after && w))
  2939                  info->add_timestamp = RB_ADD_STAMP_FORCE;
  2940          /*
  2941           * If the time delta since the last event is too big to
  2942           * hold in the time field of the event, then we append a
  2943           * TIME EXTEND event ahead of the data event.
  2944           */
  2945          if (unlikely(info->add_timestamp))
  2946                  info->length += RB_LEN_TIME_EXTEND;
  2947  
  2948          next = READ_ONCE(cpu_buffer->next_write);
  2949          WRITE_ONCE(cpu_buffer->next_write, w + info->length);
  2950  
  2951   /*B*/  local64_set(&cpu_buffer->before_stamp, info->ts);
  2952  
  2953   /*C*/  write = local_add_return(info->length, &tail_page->write);
  2954  
  2955          /* set write to only the index of the write */
  2956          write &= RB_WRITE_MASK;
  2957  
  2958          tail = write - info->length;
  2959  
  2960          /* See if we shot pass the end of this buffer page */
  2961          if (unlikely(write > BUF_PAGE_SIZE)) {
  2962                  if (tail != w) {
  2963                          /* before and after may now different, fix it 
up*/
  2964                          before = 
local64_read(&cpu_buffer->before_stamp);
  2965                          after = local64_read(&cpu_buffer->write_stamp);
  2966                          if (before != after)
  2967                                  
(void)local64_cmpxchg(&cpu_buffer->before_stamp, before, after);
  2968                  }
  2969                  return rb_move_tail(cpu_buffer, tail, info);
  2970          }
  2971  
  2972          if (likely(tail == w)) {
  2973                  u64 save_before;
  2974  
  2975                  /* Nothing interrupted us between A and C */
  2976   /*D*/          local64_set(&cpu_buffer->write_stamp, info->ts);
  2977                  barrier();
  2978   /*E*/          save_before = local64_read(&cpu_buffer->before_stamp);
  2979                  if (likely(info->add_timestamp != RB_ADD_STAMP_FORCE))
  2980                          /* This did not interrupt any time update */
  2981                          info->delta = info->ts - after;
  2982                  else
  2983                          /* Just use full timestamp for inerrupting 
event */
  2984                          info->delta = info->ts;
  2985                  barrier();
  2986                  if (unlikely(info->ts != save_before)) {
  2987                          /* SLOW PATH - Interrupted between C and E */
  2988  
  2989                          after = local64_read(&cpu_buffer->write_stamp);
  2990                          /* Write stamp must only go forward */
  2991                          if (save_before > after) {
  2992                                  /*
  2993                                   * We do not care about the result, 
only that
  2994                                   * it gets updated atomically.
  2995                                   */
  2996                                  
(void)local64_cmpxchg(&cpu_buffer->write_stamp, after, save_before);
  2997                          }
  2998                  }
  2999          } else {
  3000                  u64 ts;
  3001                  /* SLOW PATH - Interrupted between A and C */
  3002                  after = local64_read(&cpu_buffer->write_stamp);
  3003                  ts = rb_time_stamp(cpu_buffer->buffer);
  3004                  barrier();
  3005   /*E*/          if (write == (local_read(&tail_page->write) & 
RB_WRITE_MASK) &&
  3006                      after < ts) {
  3007                          /* Nothing came after this event between C and 
E */
  3008                          info->delta = ts - after;
  3009                          (void)local64_cmpxchg(&cpu_buffer->write_stamp, 
after, info->ts);
  3010                          info->ts = ts;
  3011                  } else {
  3012                          /*
  3013                           * Interrupted beween C and E:
  3014                           * Lost the previous events time stamp. Just 
set the
  3015                           * delta to zero, and this will be the same 
time as
  3016                           * the event this event interrupted. And the 
events that
  3017                           * came after this will still be correct (as 
they would
  3018                           * have built their delta on the previous event.
  3019                           */
  3020                          info->delta = 0;
  3021                  }
  3022                  if (info->add_timestamp == RB_ADD_STAMP_FORCE)
  3023                          info->add_timestamp = RB_ADD_STAMP_NORMAL;
  3024          }
  3025  
  3026          /*
  3027           * If this is the first commit on the page, then it has the same
  3028           * timestamp as the page itself.
  3029           */
  3030          if (unlikely(!tail && info->add_timestamp != RB_ADD_STAMP_FORCE 
&& !abs))
  3031                  info->delta = 0;
  3032  
  3033          /* We reserved something on the buffer */
  3034  
  3035          event = __rb_page_index(tail_page, tail);
  3036          rb_update_event(cpu_buffer, event, info);
  3037  
  3038          local_inc(&tail_page->entries);
  3039  
  3040          /*
  3041           * If this is the first commit on the page, then update
  3042           * its timestamp.
  3043           */
  3044          if (!tail)
  3045                  tail_page->page->time_stamp = info->ts;
  3046  
  3047          /* account for these added bytes */
  3048          local_add(info->length, &cpu_buffer->entries_bytes);
  3049  
  3050          return event;
  3051  }
  3052  

---
0-DAY CI Kernel Test Service, Intel Corporation
https://lists.01.org/hyperkitty/list/kbuild-...@lists.01.org

Attachment: .config.gz
Description: application/gzip

Reply via email to