Merge tag 'trace-v4.18-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace

Pull tracing fixes from Steven Rostedt:
"This contains a few fixes and a clean up.

- a bad merge caused an "endif" to go in the wrong place in
scripts/Makefile.build

- softirq tracing fix for tracing that corrupts lockdep and causes a
false splat

- histogram documentation typo fixes

- fix a bad memory reference when passing in no filter to the filter
code

- simplify code by using the swap macro instead of open coding the
swap"

* tag 'trace-v4.18-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace:
tracing: Fix SKIP_STACK_VALIDATION=1 build due to bad merge with -mrecord-mcount
tracing: Fix some errors in histogram documentation
tracing: Use swap macro in update_max_tr
softirq: Reorder trace_softirqs_on to prevent lockdep splat
tracing: Check for no filter when processing event filters

+28 -19
+12 -11
Documentation/trace/histogram.txt
··· 1729 associated event field will be saved in a variable but won't be summed 1730 as a value: 1731 1732 - # echo 'hist:keys=next_pid:ts1=common_timestamp ... >> event/trigger 1733 1734 Multiple variables can be assigned at the same time. The below would 1735 result in both ts0 and b being created as variables, with both 1736 common_timestamp and field1 additionally being summed as values: 1737 1738 - # echo 'hist:keys=pid:vals=$ts0,$b:ts0=common_timestamp,b=field1 ... >> \ 1739 event/trigger 1740 1741 Note that variable assignments can appear either preceding or 1742 following their use. The command below behaves identically to the 1743 command above: 1744 1745 - # echo 'hist:keys=pid:ts0=common_timestamp,b=field1:vals=$ts0,$b ... >> \ 1746 event/trigger 1747 1748 Any number of variables not bound to a 'vals=' prefix can also be 1749 assigned by simply separating them with colons. Below is the same 1750 thing but without the values being summed in the histogram: 1751 1752 - # echo 'hist:keys=pid:ts0=common_timestamp:b=field1 ... >> event/trigger 1753 1754 Variables set as above can be referenced and used in expressions on 1755 another event. 1756 1757 For example, here's how a latency can be calculated: 1758 1759 - # echo 'hist:keys=pid,prio:ts0=common_timestamp ... >> event1/trigger 1760 - # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp-$ts0 ... >> event2/trigger 1761 1762 In the first line above, the event's timetamp is saved into the 1763 variable ts0. In the next line, ts0 is subtracted from the second ··· 1766 makes use of the wakeup_lat variable to compute a combined latency 1767 using the same key and variable from yet another event: 1768 1769 - # echo 'hist:key=pid:wakeupswitch_lat=$wakeup_lat+$switchtime_lat ... >> event3/trigger 1770 1771 2.2.2 Synthetic Events 1772 ---------------------- ··· 1807 At this point, there isn't yet an actual 'wakeup_latency' event 1808 instantiated in the event subsytem - for this to happen, a 'hist 1809 trigger action' needs to be instantiated and bound to actual fields 1810 - and variables defined on other events (see Section 6.3.3 below). 1811 1812 - Once that is done, an event instance is created, and a histogram can 1813 - be defined using it: 1814 1815 # echo 'hist:keys=pid,prio,lat.log2:sort=pid,lat' >> \ 1816 /sys/kernel/debug/tracing/events/synthetic/wakeup_latency/trigger ··· 1961 back to that pid, the timestamp difference is calculated. If the 1962 resulting latency, stored in wakeup_lat, exceeds the current 1963 maximum latency, the values specified in the save() fields are 1964 - recoreded: 1965 1966 # echo 'hist:keys=pid:ts0=common_timestamp.usecs \ 1967 if comm=="cyclictest"' >> \
··· 1729 associated event field will be saved in a variable but won't be summed 1730 as a value: 1731 1732 + # echo 'hist:keys=next_pid:ts1=common_timestamp ...' >> event/trigger 1733 1734 Multiple variables can be assigned at the same time. The below would 1735 result in both ts0 and b being created as variables, with both 1736 common_timestamp and field1 additionally being summed as values: 1737 1738 + # echo 'hist:keys=pid:vals=$ts0,$b:ts0=common_timestamp,b=field1 ...' >> \ 1739 event/trigger 1740 1741 Note that variable assignments can appear either preceding or 1742 following their use. The command below behaves identically to the 1743 command above: 1744 1745 + # echo 'hist:keys=pid:ts0=common_timestamp,b=field1:vals=$ts0,$b ...' >> \ 1746 event/trigger 1747 1748 Any number of variables not bound to a 'vals=' prefix can also be 1749 assigned by simply separating them with colons. Below is the same 1750 thing but without the values being summed in the histogram: 1751 1752 + # echo 'hist:keys=pid:ts0=common_timestamp:b=field1 ...' >> event/trigger 1753 1754 Variables set as above can be referenced and used in expressions on 1755 another event. 1756 1757 For example, here's how a latency can be calculated: 1758 1759 + # echo 'hist:keys=pid,prio:ts0=common_timestamp ...' >> event1/trigger 1760 + # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp-$ts0 ...' >> event2/trigger 1761 1762 In the first line above, the event's timetamp is saved into the 1763 variable ts0. In the next line, ts0 is subtracted from the second ··· 1766 makes use of the wakeup_lat variable to compute a combined latency 1767 using the same key and variable from yet another event: 1768 1769 + # echo 'hist:key=pid:wakeupswitch_lat=$wakeup_lat+$switchtime_lat ...' >> event3/trigger 1770 1771 2.2.2 Synthetic Events 1772 ---------------------- ··· 1807 At this point, there isn't yet an actual 'wakeup_latency' event 1808 instantiated in the event subsytem - for this to happen, a 'hist 1809 trigger action' needs to be instantiated and bound to actual fields 1810 + and variables defined on other events (see Section 2.2.3 below on 1811 + how that is done using hist trigger 'onmatch' action). Once that is 1812 + done, the 'wakeup_latency' synthetic event instance is created. 1813 1814 + A histogram can now be defined for the new synthetic event: 1815 1816 # echo 'hist:keys=pid,prio,lat.log2:sort=pid,lat' >> \ 1817 /sys/kernel/debug/tracing/events/synthetic/wakeup_latency/trigger ··· 1960 back to that pid, the timestamp difference is calculated. If the 1961 resulting latency, stored in wakeup_lat, exceeds the current 1962 maximum latency, the values specified in the save() fields are 1963 + recorded: 1964 1965 # echo 'hist:keys=pid:ts0=common_timestamp.usecs \ 1966 if comm=="cyclictest"' >> \
+5 -1
kernel/softirq.c
··· 139 { 140 lockdep_assert_irqs_disabled(); 141 142 if (softirq_count() == (cnt & SOFTIRQ_MASK)) 143 trace_softirqs_on(_RET_IP_); 144 - preempt_count_sub(cnt); 145 } 146 147 /*
··· 139 { 140 lockdep_assert_irqs_disabled(); 141 142 + if (preempt_count() == cnt) 143 + trace_preempt_on(CALLER_ADDR0, get_lock_parent_ip()); 144 + 145 if (softirq_count() == (cnt & SOFTIRQ_MASK)) 146 trace_softirqs_on(_RET_IP_); 147 + 148 + __preempt_count_sub(cnt); 149 } 150 151 /*
+1 -5
kernel/trace/trace.c
··· 1360 void 1361 update_max_tr(struct trace_array *tr, struct task_struct *tsk, int cpu) 1362 { 1363 - struct ring_buffer *buf; 1364 - 1365 if (tr->stop_count) 1366 return; 1367 ··· 1373 1374 arch_spin_lock(&tr->max_lock); 1375 1376 - buf = tr->trace_buffer.buffer; 1377 - tr->trace_buffer.buffer = tr->max_buffer.buffer; 1378 - tr->max_buffer.buffer = buf; 1379 1380 __update_max_tr(tr, tsk, cpu); 1381 arch_spin_unlock(&tr->max_lock);
··· 1360 void 1361 update_max_tr(struct trace_array *tr, struct task_struct *tsk, int cpu) 1362 { 1363 if (tr->stop_count) 1364 return; 1365 ··· 1375 1376 arch_spin_lock(&tr->max_lock); 1377 1378 + swap(tr->trace_buffer.buffer, tr->max_buffer.buffer); 1379 1380 __update_max_tr(tr, tsk, cpu); 1381 arch_spin_unlock(&tr->max_lock);
+9 -1
kernel/trace/trace_events_filter.c
··· 78 C(TOO_MANY_PREDS, "Too many terms in predicate expression"), \ 79 C(INVALID_FILTER, "Meaningless filter expression"), \ 80 C(IP_FIELD_ONLY, "Only 'ip' field is supported for function trace"), \ 81 - C(INVALID_VALUE, "Invalid value (did you forget quotes)?"), 82 83 #undef C 84 #define C(a, b) FILT_ERR_##a ··· 548 if (top != op_stack) { 549 /* Too many '(' */ 550 parse_error(pe, FILT_ERR_TOO_MANY_OPEN, ptr - str); 551 goto out_free; 552 } 553
··· 78 C(TOO_MANY_PREDS, "Too many terms in predicate expression"), \ 79 C(INVALID_FILTER, "Meaningless filter expression"), \ 80 C(IP_FIELD_ONLY, "Only 'ip' field is supported for function trace"), \ 81 + C(INVALID_VALUE, "Invalid value (did you forget quotes)?"), \ 82 + C(NO_FILTER, "No filter found"), 83 84 #undef C 85 #define C(a, b) FILT_ERR_##a ··· 547 if (top != op_stack) { 548 /* Too many '(' */ 549 parse_error(pe, FILT_ERR_TOO_MANY_OPEN, ptr - str); 550 + goto out_free; 551 + } 552 + 553 + if (!N) { 554 + /* No program? */ 555 + ret = -EINVAL; 556 + parse_error(pe, FILT_ERR_NO_FILTER, ptr - str); 557 goto out_free; 558 } 559
+1 -1
scripts/Makefile.build
··· 239 "$(CC_FLAGS_FTRACE)" ]; then \ 240 $(sub_cmd_record_mcount) \ 241 fi; 242 endif # CONFIG_FTRACE_MCOUNT_RECORD 243 244 ifdef CONFIG_STACK_VALIDATION ··· 262 ifdef CONFIG_RETPOLINE 263 ifneq ($(RETPOLINE_CFLAGS),) 264 objtool_args += --retpoline 265 - endif 266 endif 267 endif 268
··· 239 "$(CC_FLAGS_FTRACE)" ]; then \ 240 $(sub_cmd_record_mcount) \ 241 fi; 242 + endif # -record-mcount 243 endif # CONFIG_FTRACE_MCOUNT_RECORD 244 245 ifdef CONFIG_STACK_VALIDATION ··· 261 ifdef CONFIG_RETPOLINE 262 ifneq ($(RETPOLINE_CFLAGS),) 263 objtool_args += --retpoline 264 endif 265 endif 266