Skip to content

[FEATURE] Switch implementation of IPC payload dump to Linux BPF #1201

Open
Open
[FEATURE] Switch implementation of IPC payload dump to Linux BPF#1201
Labels
area:logsLog and results collection, storage, etc.type:enhancementNew framework feature or request

Description

@kv2019i
kv2019i
opened on May 31, 2024

Follow-up discussion at thesofproject/sof#9123 (comment)

To reduce the overhead of IPC payload dump, BPF should be used to enable the feature universally.

BFP script already drafted in comment thesofproject/sof#9123 (comment)

Activity

  1. kv2019i
    added
    type:enhancementNew framework feature or request
    on May 31, 2024

  2. ujfalusi commented on May 31, 2024

    @ujfalusi
    ujfalusi
    on May 31, 2024
    Contributor

    for the record, the bpf script to capture the tx IPC messages with payload (the rx trace position update message is ignored):

    #!/usr/bin/bpftrace
   
struct sof_ipc4_msg {
	union {
		unsigned long header_u64;
		struct {
			unsigned int primary;
			unsigned int extension;
		};
	};

	unsigned long data_size;
	void *data_ptr;
};
 
BEGIN
{
	printf("SOF IPC4 tx message logging. Ctrl-C to end.\n\n");
}

/*
 * Log the sent IPC4 messages, ignoring the 0x1b060000 notification
 * from firmware (trace update)
 * The message payload is printed as bytes, arranged by 16 bytes/line
 */
kprobe:sof_ipc4_log_header {
	$msg = (struct sof_ipc4_msg *)arg2;

	if ($msg->primary != 0x1b060000 && arg3 == 1 && $msg->data_size != 0) {
		printf("%s : 0x%x|0x%x [data size:: %llu]\n", str(arg1),
		       $msg->primary, $msg->extension, $msg->data_size);
		if (!strcontains(str(arg1), "done")) {
			$count = (int64) $msg->data_size;
			$ptr = (uint8*) $msg->data_ptr;
			$line = 0;

			printf("Message payload:\n");
			while ($line < 500) {
				if ($count <= 16) {
					printf("%rh\n", buf($ptr, $count));
					break;
				}

				printf("%rh\n", buf($ptr, 16));
				$count -= 16;
				if ($count == 0) {
					break;
				}
				$ptr += 16;
				$line++;
			}
		} else {
			printf("\n");
		}
	} else if ($msg->primary != 0x1b060000) {
		printf("%s : 0x%x|0x%x\n", str(arg1), $msg->primary,
		       $msg->extension);
		if (strcontains(str(arg1), "done")) {
			printf("\n");
		}
	}	
}

    the log:

    sof-up-xtreme:[root]:~# ./ipc4_msg_trace.bt
Attaching 2 probes...
SOF IPC4 tx message logging. Ctrl-C to end.

ipc rx       : 0x1b080000|0x0
ipc rx done  : 0x1b080000|0x0

ipc tx       : 0x44000000|0x31400008 [data size:: 8]
Message payload:
f8 7a c2 25 05 00 00 00
ipc tx reply : 0x64000000|0x31400008
ipc tx done  : 0x44000000|0x31400008 [data size:: 8]

ipc tx       : 0x44000000|0x3060004c [data size:: 76]
Message payload:
00 01 00 00 00 10 00 00 01 00 00 00 ef 01 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00
ipc tx reply : 0x64000000|0x3060004c
ipc tx done  : 0x44000000|0x3060004c [data size:: 76]

ipc tx       : 0x11000005|0x0
ipc tx reply : 0x31000000|0x0
ipc tx done  : 0x11000005|0x0

ipc tx       : 0x40000004|0x15 [data size:: 84]
Message payload:
00 00 00 00 c0 00 00 00 80 01 00 00 01 00 00 00
80 bb 00 00 10 00 00 00 10 ff ff ff 01 00 00 00
00 00 00 00 02 10 01 00 80 bb 00 00 20 00 00 00
10 ff ff ff 01 00 00 00 00 00 00 00 02 20 01 00
00 00 00 00 00 00 00 00 80 01 00 00 01 00 00 00
00 00 00 00
ipc tx reply : 0x60000000|0x15
ipc tx done  : 0x40000004|0x15 [data size:: 84]

ipc tx       : 0x40000006|0x10 [data size:: 64]
Message payload:
00 00 00 00 80 01 00 00 80 01 00 00 00 00 00 00
80 bb 00 00 20 00 00 00 10 ff ff ff 01 00 00 00
00 00 00 00 02 20 01 00 ff ff ff ff ff ff ff 7f
02 00 00 00 00 00 00 00 40 0d 03 00 00 00 00 00
ipc tx reply : 0x60000000|0x10
ipc tx done  : 0x40000006|0x10 [data size:: 64]

ipc tx       : 0x44000006|0x30000018 [data size:: 24]
Message payload:
ff ff ff ff ff ff ff 7f 02 00 00 00 00 00 00 00
40 0d 03 00 00 00 00 00
ipc tx reply : 0x64000000|0x30000018
ipc tx done  : 0x44000006|0x30000018 [data size:: 24]

ipc tx       : 0x40000002|0xa [data size:: 40]
Message payload:
00 00 00 00 80 01 00 00 80 01 00 00 00 00 00 00
80 bb 00 00 20 00 00 00 10 ff ff ff 01 00 00 00
00 00 00 00 02 20 01 00
ipc tx reply : 0x60000000|0xa
ipc tx done  : 0x40000002|0xa [data size:: 40]

ipc tx       : 0x1101000c|0x0
ipc tx reply : 0x31000000|0x0
ipc tx done  : 0x1101000c|0x0

ipc tx       : 0x40000003|0x1000a [data size:: 40]
Message payload:
00 00 00 00 80 01 00 00 80 01 00 00 00 00 00 00
80 bb 00 00 20 00 00 00 10 ff ff ff 01 00 00 00
00 00 00 00 02 20 01 00
ipc tx reply : 0x60000000|0x1000a
ipc tx done  : 0x40000003|0x1000a [data size:: 40]

ipc tx       : 0x40010006|0x10010 [data size:: 64]
Message payload:
00 00 00 00 80 01 00 00 80 01 00 00 00 00 00 00
80 bb 00 00 20 00 00 00 10 ff ff ff 01 00 00 00
00 00 00 00 02 20 01 00 ff ff ff ff ff ff ff 7f
02 00 00 00 00 00 00 00 40 0d 03 00 00 00 00 00
ipc tx reply : 0x60000000|0x10010
ipc tx done  : 0x40010006|0x10010 [data size:: 64]

ipc tx       : 0x44010006|0x30000018 [data size:: 24]
Message payload:
ff ff ff ff ff ff ff 7f 02 00 00 00 00 00 00 00
40 0d 03 00 00 00 00 00
ipc tx reply : 0x64000000|0x30000018
ipc tx done  : 0x44010006|0x30000018 [data size:: 24]

ipc tx       : 0x4000000a|0x1000a [data size:: 40]
Message payload:
00 00 00 00 80 01 00 00 80 01 00 00 00 00 00 00
80 bb 00 00 20 00 00 00 10 ff ff ff 01 00 00 00
00 00 00 00 02 20 01 00
ipc tx reply : 0x60000000|0x1000a
ipc tx done  : 0x4000000a|0x1000a [data size:: 40]

ipc tx       : 0x4400000a|0x30000058 [data size:: 88]
Message payload:
58 00 00 00 02 00 00 00 01 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 ff ff ff ff
ff ff ff ff 01 00 00 00 01 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 9e 73 13 20
00 00 00 00 b2 7f 00 00
ipc tx reply : 0x64000000|0x30000058
ipc tx done  : 0x4400000a|0x30000058 [data size:: 88]

ipc tx       : 0x4000000b|0x1000a [data size:: 40]
Message payload:
00 00 00 00 80 01 00 00 80 01 00 00 00 00 00 00
80 bb 00 00 20 00 00 00 10 ff ff ff 01 00 00 00
00 00 00 00 02 20 01 00
ipc tx reply : 0x60000000|0x1000a
ipc tx done  : 0x4000000b|0x1000a [data size:: 40]

ipc tx       : 0x4400000b|0x30000038 [data size:: 56]
Message payload:
38 00 00 00 02 00 01 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 ff ff ff ff 04 00 ff ff
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 40 00 00 00 00 00 00
ipc tx reply : 0x64000000|0x30000038
ipc tx done  : 0x4400000b|0x30000038 [data size:: 56]

ipc tx       : 0x40000010|0x1000a [data size:: 40]
Message payload:
00 00 00 00 80 01 00 00 80 01 00 00 00 00 00 00
80 bb 00 00 20 00 00 00 10 ff ff ff 01 00 00 00
00 00 00 00 02 20 01 00
ipc tx reply : 0x60000000|0x1000a
ipc tx done  : 0x40000010|0x1000a [data size:: 40]

ipc tx       : 0x44000010|0x3c80001c [data size:: 28]
Message payload:
00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00
ipc tx reply : 0x64000000|0x3c80001c
ipc tx done  : 0x44000010|0x3c80001c [data size:: 28]

ipc tx       : 0x44000010|0x3000006c [data size:: 108]
Message payload:
6c 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 e8 00 00 00 1e
00 00 00 0c d3 4d 62 00 b1 c2 09 04 55 55 55 05
50 fa 1e 00 55 60 94 00 7e 98 6a ff 83 c9 fe 01
64 47 47 22 17 56 74 01 1c c7 71 00 77 77 77 ff
d8 77 1f 00 05 00 00 00 00 80 43 00 d7 7d 04 00
a0 ce 25 00 d7 7d 09 00 b1 b5 00 00
ipc tx reply : 0x64000000|0x3000006c
ipc tx done  : 0x44000010|0x3000006c [data size:: 108]

ipc tx       : 0x40010004|0x10015 [data size:: 84]
Message payload:
00 00 00 00 80 01 00 00 80 01 00 00 01 00 00 00
80 bb 00 00 20 00 00 00 10 ff ff ff 01 00 00 00
00 00 00 00 02 20 01 00 80 bb 00 00 20 00 00 00
10 ff ff ff 01 00 00 00 00 00 00 00 02 20 01 00
00 00 00 00 00 08 00 00 00 03 00 00 01 00 00 00
00 00 00 00
ipc tx reply : 0x60000000|0x10015
ipc tx done  : 0x40010004|0x10015 [data size:: 84]

ipc tx       : 0x45000004|0x6
ipc tx reply : 0x65000000|0x6
ipc tx done  : 0x45000004|0x6

ipc tx       : 0x45000006|0x2
ipc tx reply : 0x65000000|0x2
ipc tx done  : 0x45000006|0x2

ipc tx       : 0x45000002|0x3
ipc tx reply : 0x65000000|0x3
ipc tx done  : 0x45000002|0x3

ipc tx       : 0x45000003|0x10006
ipc tx reply : 0x65000000|0x10006
ipc tx done  : 0x45000003|0x10006

ipc tx       : 0x45010006|0xa
ipc tx reply : 0x65000000|0xa
ipc tx done  : 0x45010006|0xa

ipc tx       : 0x4500000a|0xb
ipc tx reply : 0x65000000|0xb
ipc tx done  : 0x4500000a|0xb

ipc tx       : 0x4500000b|0x10
ipc tx reply : 0x65000000|0x10
ipc tx done  : 0x4500000b|0x10

ipc tx       : 0x45000010|0x10004
ipc tx reply : 0x65000000|0x10004
ipc tx done  : 0x45000010|0x10004

ipc tx       : 0x13010003|0x0
ipc tx reply : 0x33000000|0x0
ipc tx done  : 0x13010003|0x0

ipc tx       : 0x13010004|0x0
ipc tx reply : 0x33000000|0x0
ipc tx done  : 0x13010004|0x0

ipc tx       : 0x13000003|0x0
ipc tx reply : 0x33000000|0x0
ipc tx done  : 0x13000003|0x0

ipc tx       : 0x13000004|0x0
ipc tx reply : 0x33000000|0x0
ipc tx done  : 0x13000004|0x0

ipc tx       : 0x13000003|0x0
ipc tx reply : 0x33000000|0x0
ipc tx done  : 0x13000003|0x0

ipc tx       : 0x13010003|0x0
ipc tx reply : 0x33000000|0x0
ipc tx done  : 0x13010003|0x0

  3. marc-hb commented on Jun 5, 2024

    @marc-hb
    marc-hb
    on Jun 5, 2024
    Collaborator

    Today a question was raised: should this BPF script be hosted in sof-test.git or sof.git?

    The most important point to consider for any test code is: how tightly coupled with production code is it? If tightly coupled (e.g.: unit tests), then the test code should live in the same repo, otherwise there will be mismatches and breakages all the time. If very loose then it should live in the separate sof-test.git for flexibility.

    The best litmus test is: imagine you're bisecting sof.git. Would you rather this BPF script to downgrade and upgrade at the same time you're bisecting sof? Or not? Which is the more likely? Same idea with branching, rebasing, cherry-picking etc.

    As IPC4 is a very stable API, I'm guessing this BPF script should live in sof-test?

  4. plbossart commented on Jun 6, 2024

    @plbossart
    plbossart
    on Jun 6, 2024
    Member

    My take is that BPF can provide access to lots of Linux kernel functions, and as such isn't guaranteed to be stable over time. Bisecting with BPF may or may not be possible between different Linux versions.

    https://lwn.net/Articles/921088/

    That means that if/when there are changes to the kernel, the scripts shall be updated.
    We have similar issues with kmod scripts, the names of modules and the list of modules may change over time.

  5. ujfalusi commented on Jun 6, 2024

    @ujfalusi
    ujfalusi
    on Jun 6, 2024
    Contributor

    @plbossart, I agree that there is a risk of kernel change breaking the BPF script, I'm proposing to tap on the sof_ipc4_log_header() which is not expected to change (famous last words?).
    We can only get the TX message payloads reliably, I'm not sure if there is a way around to get the reply and I don't plan to decode the notification payload.
    For the reply payload we might be able to use kretprobe with saving pointer in kprope and then using that to print the received reply payload, but I have not tried that and I find that a bit more risky than the send IPC message traffic.

  6. marc-hb commented on Jun 6, 2024

    @marc-hb
    marc-hb
    on Jun 6, 2024
    Collaborator

    I agree that there is a risk of kernel change breaking the BPF script

    Then the ideal git repo for the BPF script would be the kernel repo; that's the one it's most tightly coupled with. But that's not possible because https://thesofproject.github.io/latest/contribute/linux/development_tree.html#development-summary

         +----reject-----------+                      +--------merge----------------+
     |                     |                      |                             |
     v                     |                      v                             |
+----+------+        +-----+-------+       +------+--------+           +--------+----------+
| developer +------->+ SOF reviews +--ok-->+ topic/sof-dev |         +-+ upstream baseline |
| PR        |        | CI tests    |       |               |         | |                   |
+-----------+        +-----+-------+       +------+--------+         | +---------+---------+
                           |                      |                  |           ^
                           |                               +--rebase-+           |
                           |                      |        |             ALSA maintainers ok
                           |                      |        v                     |
                           |           +----------v--------+--+         +--------+----------+
                           |           | topic/sof-dev-rebase +-email-->+    alsa-devel     |
                           |           |                      |         |    mailing list   |
                           |           +----------------------+         +--------+----------+
                           |                                                     ^
                           |                                                     |
                           |                                                     |
                           +-----------------direct path (exceptions)------------+

    So is there a "second best" between sof-test.git and sof.git? Maybe not. Maybe they are both equally inferior.

  7. ujfalusi commented on Jun 7, 2024

    @ujfalusi
    ujfalusi
    on Jun 7, 2024
    Contributor

    BPF scripts are not part of the kernel tree. Ideally we should have 'trampolines' (iow, stable BPF entries) for proper support then the scripts could be part of sof-bin package.
    But we are not planning to support BPF officially and this script is for developers/CI only.

    We can also just see how things work with the dmesg dumping...

  8. plbossart commented on Jun 7, 2024

    @plbossart
    plbossart
    on Jun 7, 2024
    Member

    I don't think there's a better proposal than using sof-test for those BPF scripts, so unless there's a sustained objection let's go with that direction.

  9. ujfalusi commented on Jun 7, 2024

    @ujfalusi
    ujfalusi
    on Jun 7, 2024
    Contributor

    The initial script: #1205

  10. marc-hb commented on Jun 7, 2024

    @marc-hb
    marc-hb
    on Jun 7, 2024
    Collaborator

    We can also just see how things work with the dmesg dumping...

    Even if the current script above is just a "works4me" and does not end up being used, it is still better placed in sof-test.git than in a discussion comment.

    It's not like sof-test.git has "coverage" requirement for everything in it, pretty far from that. The bar is of course higher for code that is used every day but it is low for demos and prototypes.

    How about sof-test/BPFTrace/IPClogs.bpf ? OR something like it.

  11. marc-hb
    changed the title [-][FEATURE] Implement IPC payload dump with BFP in sof-test[/-] [+][FEATURE] Switch IPC payload dump to BPF[/+] on Aug 13, 2024
  12. marc-hb
    changed the title [-][FEATURE] Switch IPC payload dump to BPF[/-] [+][FEATURE] Switch IPC payload dump to Linux BPF[/+] on Aug 13, 2024
  13. marc-hb
    changed the title [-][FEATURE] Switch IPC payload dump to Linux BPF[/-] [+][FEATURE] Switch implementation of IPC payload dump to Linux BPF[/+] on Aug 13, 2024
  14. marc-hb
    added
    area:logsLog and results collection, storage, etc.
    on Aug 13, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    area:logsLog and results collection, storage, etc.type:enhancementNew framework feature or request

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions