Re: [PATCH v1] arch/x86: port I/O tracing on x86

From: Dan Raymond
Date: Thu Sep 21 2023 - 17:16:28 EST


On 9/19/2023 4:43 PM, Dan Raymond wrote:
> On 9/19/2023 3:31 PM, Dan Raymond wrote:
>> On 9/19/2023 3:12 PM, Peter Zijlstra wrote:
>>>>> This means I can no longer use early_console->write() to print to my
>>>>> early_serial_console.
>>>>
>>>> Why not? Did you try it?
>>>
>>> I have tried debugging the kernel for the last 15+ years. The only
>>> reliable way to get something out of the machine is outb on the serial
>>> port. Anything else is a waste of time..
>>>
>>> Adding tracing to it (which relies on RCU, which might not be alive at
>>> this point) which might itself be the problem, is a total no-go.
>>>
>>> You do not wreck early_serial_console.
>>
>> But you didn't try my patch to see if it "wrecks" early_serial_console.
>> I doubt it has any impact there because it does not get compiled into
>> boot code. Notice the BOOT_COMPRESSED_MISC_H and BOOT_BOOT_H checks.
>>
>> I don't understand your general objection. The kernel already has
>> tracing for memory mapped I/O which includes serial ports. This patch
>> just extends that to include port I/O.
>
> Another point: The tracing infrastructure uses RCU for management of
> trace buffers. If you don't explicitly enable portio tracing nothing
> will get written to the trace buffers. Nothing extra will be done
> during outb() except for a quick check to see that tracing is disabled.
> This check took only a few clock cycles on average during my testing.
> This should be fine even during early boot.

Tracing is enabled/disabled by modifying the code segment at runtime.
To demonstrate this point:

# grep do_trace_portio_write /proc/kallsyms
c13800d0 T do_trace_portio_write
c1915fd0 r __ksymtab_do_trace_portio_write
c19231b5 r __kstrtabns_do_trace_portio_write
c192ca4d r __kstrtab_do_trace_portio_write

# hexdump -C -s 0x013800d0 /dev/mem | head -1
013800d0 3e 8d 74 26 00 c3 8d b4 26 00 00 00 00 8d 76 00 |>.t&....&.....v.|

# echo 1 > /sys/kernel/tracing/events/portio/portio_write/enable
# hexdump -C -s 0x013800d0 /dev/mem | head -1
013800d0 e9 0b 00 00 00 c3 8d b4 26 00 00 00 00 8d 76 00 |........&.....v.|

Disassembling this shows what changed:

# echo "0: 3e 8d 74 26 00 c3" | xxd -r > a.out
# objdump -D -b binary -m i386
...
00000000 <.data>:
0: 3e 8d 74 26 00 lea %ds:0x0(%esi,%eiz,1),%esi
5: c3 ret

# echo "0: e9 0b 00 00 00 c3" | xxd -r > a.out
# objdump -D -b binary -m i386
...
00000000 <.data>:
0: e9 0b 00 00 00 jmp 0x10
5: c3 ret

The 'lea' instruction is a nop so when tracing is disabled this function
does nothing. When tracing is enabled the 'jmp' instruction transfers
control past the 'ret' instruction to the tracing logic.