Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]


Groups > linux.kernel > #1472499

Re: [PATCH v3 2/3] tracing: Add trace_irqsoff tracepoints

From Daniel Wagner <daniel.wagner@bmw-carit.de>
Newsgroups linux.kernel
Subject Re: [PATCH v3 2/3] tracing: Add trace_irqsoff tracepoints
Date 2016-08-30 16:10 +0200
Message-ID <sbRTH-5Ua-11@gated-at.bofh.it> (permalink)
References <sboI1-3X9-1@gated-at.bofh.it> <sboI1-3X9-9@gated-at.bofh.it> <sbrmx-5BR-9@gated-at.bofh.it> <sbNQ5-32D-3@gated-at.bofh.it> <sbRK1-5BB-15@gated-at.bofh.it>
Organization linux.* mail to news gateway

Show all headers | View raw


Hi Steven,

>> 'hist:key=ltype,latency:val=hitcount:sort=latency if cpu==1'
> 
> What about using "CPU" (all caps)? Look at
> kernel/trace/trace_events_filter.c for FILTER_CPU.
> 
> Lets not add fields when we can fix the generic code to process these.

Well at least the size info needs to be added to the trace field.
Without it hist will bail out with no memory.


diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
index 03c0a48..ab8958f 100644
--- a/kernel/trace/trace_events.c
+++ b/kernel/trace/trace_events.c
@@ -152,7 +152,8 @@ EXPORT_SYMBOL_GPL(trace_define_field);
 
 #define __generic_field(type, item, filter_type)			\
 	ret = __trace_define_field(&ftrace_generic_fields, #type,	\
-				   #item, 0, 0, is_signed_type(type),	\
+				   #item, 0, sizeof(type),		\
+				   is_signed_type(type),		\
 				   filter_type);			\
 	if (ret)							\
 		return ret;


After that I get this funky report (with only 4 cpus):

echo "'hist:key=cpu,id.syscall' >
            /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/trigger

cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/hist'

# event histogram
#
# trigger info: hist:keys=cpu,id.syscall:vals=hitcount:sort=hitcount:size=2048 [active]
#

{ cpu:     262161, id: sys_newfstatat                [262] } hitcount:          1
{ cpu:     262161, id: sys_write                     [  1] } hitcount:          1
{ cpu:     262161, id: sys_read                      [  0] } hitcount:          1
{ cpu:     262161, id: sys_recvmsg                   [ 47] } hitcount:          1
{ cpu:         17, id: sys_inotify_init1             [294] } hitcount:          2
{ cpu:         17, id: sys_mknod                     [133] } hitcount:          2
{ cpu:         17, id: sys_setuid                    [105] } hitcount:          2
{ cpu:         17, id: sys_getcwd                    [ 79] } hitcount:          2
{ cpu:         17, id: sys_accept                    [ 43] } hitcount:          2
{ cpu:         17, id: sys_chroot                    [161] } hitcount:          2
{ cpu:         17, id: sys_fadvise64                 [221] } hitcount:          2
{ cpu:         17, id: sys_umount                    [166] } hitcount:          2
{ cpu:         17, id: sys_rt_sigtimedwait           [128] } hitcount:          2
{ cpu:         17, id: sys_mount                     [165] } hitcount:          2
{ cpu:     262161, id: sys_close                     [  3] } hitcount:          2
{ cpu:     262161, id: sys_newfstat                  [  5] } hitcount:          2
{ cpu:     262161, id: sys_getrandom                 [318] } hitcount:          3
{ cpu:     262161, id: sys_open                      [  2] } hitcount:          3
{ cpu:         17, id: sys_setgid                    [106] } hitcount:          4
{ cpu:         17, id: sys_inotify_add_watch         [254] } hitcount:          4
{ cpu:         17, id: sys_setpriority               [141] } hitcount:          4
{ cpu:         17, id: sys_getpriority               [140] } hitcount:          4
{ cpu:         17, id: sys_eventfd2                  [290] } hitcount:          4
{ cpu:         17, id: sys_listen                    [ 50] } hitcount:          4
{ cpu:         17, id: sys_timerfd_create            [283] } hitcount:          4
{ cpu:         17, id: sys_dup                       [ 32] } hitcount:          4
{ cpu:         17, id: sys_fstatfs                   [138] } hitcount:          5
{ cpu:         17, id: sys_ftruncate                 [ 77] } hitcount:          5
{ cpu:         17, id: sys_socketpair                [ 53] } hitcount:          6
{ cpu:         17, id: sys_name_to_handle_at         [303] } hitcount:          6
{ cpu:         17, id: sys_chmod                     [ 90] } hitcount:          6
{ cpu:         17, id: sys_chown                     [ 92] } hitcount:          6
{ cpu:         17, id: sys_readlink                  [ 89] } hitcount:          6
{ cpu:         17, id: sys_getpid                    [ 39] } hitcount:          8
{ cpu:         17, id: sys_unlinkat                  [263] } hitcount:          8
{ cpu:         17, id: sys_setrlimit                 [160] } hitcount:          8
{ cpu:         17, id: sys_sysinfo                   [ 99] } hitcount:          8
{ cpu:         17, id: sys_getpgrp                   [111] } hitcount:          8
{ cpu:         17, id: sys_getgroups                 [115] } hitcount:         10
{ cpu:         17, id: sys_setsid                    [112] } hitcount:         10
{ cpu:         17, id: sys_getpeername               [ 52] } hitcount:         10
{ cpu:         17, id: sys_gettid                    [186] } hitcount:         10
{ cpu:         17, id: sys_shutdown                  [ 48] } hitcount:         12
{ cpu:         17, id: sys_getppid                   [110] } hitcount:         12
{ cpu:         17, id: sys_chdir                     [ 80] } hitcount:         14
{ cpu:         17, id: sys_alarm                     [ 37] } hitcount:         14
{ cpu:         17, id: sys_pipe                      [ 22] } hitcount:         14
{ cpu:         17, id: sys_keyctl                    [250] } hitcount:         15
{ cpu:         17, id: sys_sendto                    [ 44] } hitcount:         19
{ cpu:         17, id: unknown_syscall               [ 15] } hitcount:         20
{ cpu:         17, id: sys_utimensat                 [280] } hitcount:         21
{ cpu:         17, id: sys_faccessat                 [269] } hitcount:         22
{ cpu:         17, id: sys_setgroups                 [116] } hitcount:         22
{ cpu:         17, id: sys_pipe2                     [293] } hitcount:         22
{ cpu:         17, id: sys_setresgid                 [119] } hitcount:         24
{ cpu:         17, id: sys_accept4                   [288] } hitcount:         26
{ cpu:         17, id: sys_setresuid                 [117] } hitcount:         26
{ cpu:         17, id: unknown_syscall               [ 59] } hitcount:         28
{ cpu:         17, id: sys_futex                     [202] } hitcount:         29
{ cpu:         17, id: unknown_syscall               [312] } hitcount:         34
{ cpu:         17, id: sys_waitid                    [247] } hitcount:         36
{ cpu:         17, id: sys_select                    [ 23] } hitcount:         37
{ cpu:         17, id: sys_fchmod                    [ 91] } hitcount:         49
{ cpu:         17, id: sys_statfs                    [137] } hitcount:         52
{ cpu:         17, id: sys_rename                    [ 82] } hitcount:         55
{ cpu:         17, id: sys_openat                    [257] } hitcount:         64
{ cpu:         17, id: sys_newuname                  [ 63] } hitcount:         68
{ cpu:         17, id: sys_getegid                   [108] } hitcount:         69
{ cpu:         17, id: sys_getgid                    [104] } hitcount:         70
{ cpu:         17, id: sys_connect                   [ 42] } hitcount:         76
{ cpu:         17, id: sys_signalfd4                 [289] } hitcount:         83
{ cpu:         17, id: sys_epoll_create1             [291] } hitcount:         85
{ cpu:         17, id: sys_set_tid_address           [218] } hitcount:         90
{ cpu:         17, id: sys_kill                      [ 62] } hitcount:         91
{ cpu:         17, id: sys_bind                      [ 49] } hitcount:         91
{ cpu:         17, id: unknown_syscall               [158] } hitcount:        102
{ cpu:         17, id: sys_prctl                     [157] } hitcount:        117
{ cpu:         17, id: unknown_syscall               [ 56] } hitcount:        117
{ cpu:         17, id: sys_geteuid                   [107] } hitcount:        119
{ cpu:         17, id: sys_ioctl                     [ 16] } hitcount:        120
{ cpu:         17, id: sys_dup2                      [ 33] } hitcount:        125
{ cpu:         17, id: sys_ppoll                     [271] } hitcount:        150
{ cpu:         17, id: sys_getuid                    [102] } hitcount:        160
{ cpu:         17, id: sys_getsockname               [ 51] } hitcount:        163
{ cpu:         17, id: sys_timerfd_settime           [286] } hitcount:        167
{ cpu:         17, id: sys_umask                     [ 95] } hitcount:        172
{ cpu:         17, id: sys_wait4                     [ 61] } hitcount:        186
{ cpu:         17, id: sys_exit_group                [231] } hitcount:        189
{ cpu:         17, id: sys_set_robust_list           [273] } hitcount:        191
{ cpu:         17, id: sys_lseek                     [  8] } hitcount:        196
{ cpu:         17, id: sys_rmdir                     [ 84] } hitcount:        210
{ cpu:         17, id: sys_mkdir                     [ 83] } hitcount:        211
{ cpu:         17, id: sys_setsockopt                [ 54] } hitcount:        215
{ cpu:         17, id: sys_poll                      [  7] } hitcount:        221
{ cpu:         17, id: sys_unlink                    [ 87] } hitcount:        221
{ cpu:         17, id: sys_getsockopt                [ 55] } hitcount:        222
{ cpu:         17, id: sys_socket                    [ 41] } hitcount:        229
{ cpu:         17, id: sys_munmap                    [ 11] } hitcount:        260
{ cpu:         17, id: sys_getrlimit                 [ 97] } hitcount:        318
{ cpu:         17, id: sys_rt_sigprocmask            [ 14] } hitcount:        344
{ cpu:         17, id: sys_access                    [ 21] } hitcount:        380
{ cpu:         17, id: sys_epoll_ctl                 [233] } hitcount:        391
{ cpu:         17, id: sys_readlinkat                [267] } hitcount:        416
{ cpu:         17, id: sys_newstat                   [  4] } hitcount:        582
{ cpu:         17, id: sys_write                     [  1] } hitcount:        694
{ cpu:         17, id: sys_rt_sigaction              [ 13] } hitcount:        732
{ cpu:         17, id: sys_brk                       [ 12] } hitcount:        736
{ cpu:         17, id: sys_fcntl                     [ 72] } hitcount:        818
{ cpu:         17, id: sys_sendmsg                   [ 46] } hitcount:        850
{ cpu:         17, id: sys_getrandom                 [318] } hitcount:        908
{ cpu:         17, id: sys_getdents                  [ 78] } hitcount:        937
{ cpu:         17, id: sys_clock_gettime             [228] } hitcount:       1015
{ cpu:         17, id: sys_epoll_wait                [232] } hitcount:       1394
{ cpu:         17, id: sys_newfstatat                [262] } hitcount:       1544
{ cpu:         17, id: sys_mprotect                  [ 10] } hitcount:       1592
{ cpu:         17, id: sys_recvmsg                   [ 47] } hitcount:       1676
{ cpu:         17, id: sys_newlstat                  [  6] } hitcount:       1897
{ cpu:         17, id: sys_mmap                      [  9] } hitcount:       2474
{ cpu:         17, id: sys_newfstat                  [  5] } hitcount:       3301
{ cpu:         17, id: sys_read                      [  0] } hitcount:       3570
{ cpu:         17, id: sys_open                      [  2] } hitcount:       4191
{ cpu:         17, id: sys_close                     [  3] } hitcount:       4194

Totals:
    Hits: 40593
    Entries: 122
    Dropped: 0


Still trying to figure out what's going wrong here.

cheers,
daniel

Back to linux.kernel | Previous | NextPrevious in thread | Next in thread | Find similar | Unroll thread


Thread

[PATCH v3 0/3] *** Latency histograms - IRQSOFF,PREEMPTOFF *** Binoy Jayan <binoy.jayan@linaro.org> - 2016-08-29 09:00 +0200
  [PATCH v3 2/3] tracing: Add trace_irqsoff tracepoints Binoy Jayan <binoy.jayan@linaro.org> - 2016-08-29 09:00 +0200
    Re: [PATCH v3 2/3] tracing: Add trace_irqsoff tracepoints Daniel Wagner <daniel.wagner@bmw-carit.de> - 2016-08-29 11:50 +0200
      Re: [PATCH v3 2/3] tracing: Add trace_irqsoff tracepoints Binoy Jayan <binoy.jayan@linaro.org> - 2016-08-30 11:50 +0200
        Re: [PATCH v3 2/3] tracing: Add trace_irqsoff tracepoints Steven Rostedt <rostedt@goodmis.org> - 2016-08-30 16:00 +0200
          Re: [PATCH v3 2/3] tracing: Add trace_irqsoff tracepoints Daniel Wagner <daniel.wagner@bmw-carit.de> - 2016-08-30 16:10 +0200
            Re: [PATCH v3 2/3] tracing: Add trace_irqsoff tracepoints Daniel Wagner <daniel.wagner@bmw-carit.de> - 2016-08-30 16:30 +0200
              Re: [PATCH v3 2/3] tracing: Add trace_irqsoff tracepoints Daniel Wagner <daniel.wagner@bmw-carit.de> - 2016-08-30 17:10 +0200
                Re: [PATCH v3 2/3] tracing: Add trace_irqsoff tracepoints Steven Rostedt <rostedt@goodmis.org> - 2016-08-30 23:10 +0200
                Re: [PATCH v3 2/3] tracing: Add trace_irqsoff tracepoints Binoy Jayan <binoy.jayan@linaro.org> - 2016-08-31 08:10 +0200
  [PATCH v3 1/3] tracing: Deference pointers without RCU checks Binoy Jayan <binoy.jayan@linaro.org> - 2016-08-29 09:00 +0200
  [PATCH v3 3/3] tracing: Histogram for missed timer offsets Binoy Jayan <binoy.jayan@linaro.org> - 2016-08-29 09:10 +0200

csiph-web