linux-kernel - Re: [PATCH] io_uring: Add to traces the req pointer when available

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: <fc0e08faf765b50d5f0a38b026d5ed0dfd9d1090.camel@trillion01.com>
Date:   Wed, 26 May 2021 04:28:28 -0400
From:   Olivier Langlois <olivier@...llion01.com>
To:     Jens Axboe <axboe@...nel.dk>,
        Pavel Begunkov <asml.silence@...il.com>,
        Steven Rostedt <rostedt@...dmis.org>,
        Ingo Molnar <mingo@...hat.com>, io-uring@...r.kernel.org,
        linux-kernel@...r.kernel.org
Subject: Re: [PATCH] io_uring: Add to traces the req pointer when available

On Tue, 2021-05-25 at 16:28 -0600, Jens Axboe wrote:
> > My issue is that I haven't been able to see hashed pointers output
> > from trace.
> 
> Just a quick guess, but does it rely on using %p to print the pointers?
> 
My very limited understanding of how the trace subsystem works is that
by default, it doesn't use the provided TK_printk macro at all.

the kernel trace subsystem does format internally the passed parameters
before sending the output to a ring buffer (yes another ring!).

You can override this method through the tracing option to use printk
instead and when you do, this is where the TK_printk() macro is used.

Before I did realize that, this was making me scratch my head as to
why, I was getting a different format output. ie:

  9287.369 test/625 io_uring:io_uring_task_run(ctx: 0xffff8fbf9a834800,
opcode: 22, user_data: 216454257090494477, result: 195)
  9287.386 test/625 io_uring:io_uring_task_run(ctx: 0xffff8fbf9a834800,
opcode: 22, user_data: 216454257090494477, result: 195)

while the TK_printk macro is:
        TP_printk("ring %p, req %p, op %d, data 0x%llx",
                  __entry->ctx, __entry->req, __entry->opcode,
                  (unsigned long long) __entry->user_data)

The TK_printk macro is naming the ctx variable as 'ring', yet you still
get ctx in the trace output!

but the pointer hashing that it is supposed to do is a mystery to me...