Re: [PATCH -v2] tracing: lockdep tracepoints

[Ingo Molnar <mingo@elte.hu>]

* Peter Zijlstra <peterz@infradead.org> wrote:

> On Wed, 2009-03-04 at 12:23 +0100, Frederic Weisbecker wrote:
> > > ---
> > > Subject: tracing: lockdep tracepoints
> > > From: Peter Zijlstra <a.p.zijlstra@chello.nl>
> > > Date: Tue Mar 03 22:03:08 CET 2009
> > > 
> > > Augment the traces with lock names when lockdep is available:
> > > 
> > >  1)               |  down_read_trylock() {
> > >  1)               |    _spin_lock_irqsave() {
> > >  1)               |      /* lock_acquire: name: &sem->wait_lock */
> > >  1)   4.201 us    |    }
> > >  1)               |    _spin_unlock_irqrestore() {
> > >  1)               |      /* lock_release: name: &sem->wait_lock */
> > 
> > Nice idea.
> > I would just suggest to drop the "name:" since the comment is intuitive enough
> > to figure out what we have after lock_{release,acquire}: 
> 
> Makes sense I guess..
> 
> Here goes.. one s/name: //g later
> 
> ---
> Subject: tracing: lockdep tracepoints
> From: Peter Zijlstra <a.p.zijlstra@chello.nl>
> Date: Tue Mar 03 22:03:08 CET 2009
> 
> Augment the traces with lock names when lockdep is available:
> 
>  1)               |  down_read_trylock() {
>  1)               |    _spin_lock_irqsave() {
>  1)               |      /* lock_acquire: &sem->wait_lock */
>  1)   4.201 us    |    }
>  1)               |    _spin_unlock_irqrestore() {
>  1)               |      /* lock_release: &sem->wait_lock */
>  1)   3.523 us    |    }
>  1)               |  /* lock_acquire: try read &mm->mmap_sem */
>  1) + 13.386 us   |  }

very nice! :-)

>  1)   1.460 us    |      page_add_file_rmap();
>  1)               |      _spin_unlock() {
>  1)               |        /* lock_release: __pte_lockptr(page) */
>  1)   3.115 us    |      }
>  1)               |      unlock_page() {
>  1)   1.421 us    |        page_waitqueue();
>  1)   1.220 us    |        __wake_up_bit();
>  1)   6.519 us    |      }

btw., we might want to add tracepoints for 
pagelock-acquire/release events too?

> +TRACE_FORMAT(lock_contended,
> +	TPPROTO(struct lockdep_map *lock, unsigned long ip),
> +	TPARGS(lock, ip),
> +	TPFMT("%s", lock->name)
> +	);

Would it be possible to use the C syntax tracepoints perhaps? 
They are bigger:

     TRACE_EVENT_FORMAT(sched_switch,
        TPPROTO(struct rq *rq, struct task_struct *prev,
                struct task_struct *next),
        TPARGS(rq, prev, next),
        TPFMT("task %s:%d ==> %s:%d",
              prev->comm, prev->pid, next->comm, next->pid),
        TRACE_STRUCT(
                TRACE_FIELD(pid_t, prev_pid, prev->pid)
                TRACE_FIELD(int, prev_prio, prev->prio)
                TRACE_FIELD_SPECIAL(char next_comm[TASK_COMM_LEN],
                                    next_comm,
                                    TPCMD(memcpy(TRACE_ENTRY->next_comm,
                                                 next->comm,
                                                 TASK_COMM_LEN)))
                TRACE_FIELD(pid_t, next_pid, next->pid)
                TRACE_FIELD(int, next_prio, next->prio)
        ),
        TPRAWFMT("prev %d:%d ==> next %s:%d:%d")
        );

but a lot faster.

	Ingo