linux-kernel - Re: [PATCH 00/32] tracing: Inter-event (e.g. latency) support

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <1498676971.27662.28.camel@tzanussi-mobl.amr.corp.intel.com>
Date:   Wed, 28 Jun 2017 14:09:31 -0500
From:   Tom Zanussi <tom.zanussi@...ux.intel.com>
To:     Masami Hiramatsu <mhiramat@...nel.org>
Cc:     rostedt@...dmis.org, tglx@...utronix.de, namhyung@...nel.org,
        vedang.patel@...el.com, linux-kernel@...r.kernel.org,
        linux-rt-users@...r.kernel.org
Subject: Re: [PATCH 00/32]  tracing: Inter-event (e.g. latency) support

Hi Masami,

On Wed, 2017-06-28 at 23:21 +0900, Masami Hiramatsu wrote:
> Hi Tom,
> 
> On Mon, 26 Jun 2017 17:49:01 -0500
> Tom Zanussi <tom.zanussi@...ux.intel.com> wrote:
> 
> > This patchset adds support for 'inter-event' quantities to the trace
> > event subsystem.  The most important example of inter-event quantities
> > are latencies, or the time differences between two events.
> > 
> 
> Thank you for your great work!
> I'm playing this and found some issues.
> 
> (1) new event format
> ----
> # echo "wakeup_latency u64 lat; pid_t pid; int prio" > synthetic_events 
> # cat /sys/kernel/debug/tracing # cat events/synthetic/wakeup_latency/format 
> name: wakeup_latency
> ID: 972
> format:
> 	field:unsigned short common_type;	offset:0;	size:2;	signed:0;
> 	field:unsigned char common_flags;	offset:2;	size:1;	signed:0;
> 	field:unsigned char common_preempt_count;	offset:3;	size:1;signed:0;
> 	field:int common_pid;	offset:4;	size:4;	signed:1;
> 
> 	field:u64 lat;	offset:16;	size:8;	signed:0;
> 	field:pid_t pid;	offset:24;	size:4;	signed:1;
> 	field:int prio;	offset:32;	size:4;	signed:1;
> 
> print fmt: "lat: 0x%08lx, pid: 0x%08lx, prio: 0x%08lx", ((u64)(REC->lat)), ((u64)(REC->pid)), ((u64)(REC->prio))
> ----
> Here, IMO, this format would be better "lat=0x%08lx pid=0x%08lx prio=0x%08lx" so that perf-script can parse it correctly.
> 

OK, will change it.

> (2) lockdep found a dead lock case
> When I added a histogram trigger, it happened.
> ----
> # echo 'hist:keys=pid:ts0=$common_timestamp.usecs' >>  /sys/kernel/debug/tracing/events/sched/sched_wakeup/trigger
> [33967.672485] 
> [33967.673117] ======================================================
> [33967.673117] WARNING: possible circular locking dependency detected
> [33967.673117] 4.12.0-rc5+ #1 Not tainted
> [33967.673117] ------------------------------------------------------

Yeah, will fix this and anything else similar, thanks for pointing it
out.

Tom