Skip to content
GitLab
Projects Groups Snippets
  • /
  • Help
    • Help
    • Support
    • Community forum
    • Submit feedback
    • Contribute to GitLab
  • Register
  • Sign in
  • pipewire pipewire
  • Project information
    • Project information
    • Activity
    • Labels
    • Members
  • Repository
    • Repository
    • Files
    • Commits
    • Branches
    • Tags
    • Contributors
    • Graph
    • Compare
  • Issues 608
    • Issues 608
    • List
    • Boards
    • Service Desk
    • Milestones
  • Merge requests 25
    • Merge requests 25
  • CI/CD
    • CI/CD
    • Pipelines
    • Jobs
    • Schedules
  • Deployments
    • Deployments
    • Environments
    • Releases
  • Packages and registries
    • Packages and registries
    • Container Registry
  • Monitor
    • Monitor
    • Incidents
  • Analytics
    • Analytics
    • Value stream
    • CI/CD
    • Repository
  • Wiki
    • Wiki
  • Snippets
    • Snippets
  • Activity
  • Graph
  • Create a new issue
  • Jobs
  • Commits
  • Issue Boards
Collapse sidebar

Due to an influx of spam, we have had to impose restrictions on new accounts. Please see this wiki page for instructions on how to get full permissions. Sorry for the inconvenience.

  • PipeWirePipeWire
  • pipewirepipewire
  • Issues
  • #2914
Closed
Open
Issue created Dec 28, 2022 by Barnabás Pőcze@pobrnContributor

memblock use after close leads to SIGBUS

Sometimes when setting the target of a pulseaudio stream in pavucontrol, pipewire-pulse stops with a SIGBUS. The reason for that is that it mmap()s more than the size of the file and accesses pages after the last existing one. The reason for that seems to be that pw_mempool_import_block() requires that the source block be kept alive at least as long as the imported block (because the imported block will use the same fd), but this requirement is violated somewhere.

As far as I can see the following happens:

  1. client-node.c:do_port_use_buffers() imports memblocks from from the context mempool into the client's mempool
  2. when switching stream target, when the source blocks are destroyed their file descriptors (which have been closed) are still kept in the client's mempool
  3. next time client-node.c:do_port_use_buffers() runs pw_mempool_import_block() it is possible that one of these "stale" imported memblocks are found and returned by mempool_find_fd(), thus the id of that is sent to the client, which then maps the wrong buffer
  4. SIGBUS when attempting to access the mapped region in the client process past the last valid page

After applying the following changes:

diff --git a/src/modules/module-client-node/client-node.c b/src/modules/module-client-node/client-node.c
index 563585553..516fb8c0d 100644
--- a/src/modules/module-client-node/client-node.c
+++ b/src/modules/module-client-node/client-node.c
@@ -732,6 +732,8 @@ impl_node_port_set_io(void *object,
 	return -EINVAL;
 }
 
+#include <sys/stat.h>
+
 static int
 do_port_use_buffers(struct impl *impl,
 		    enum spa_direction direction,
@@ -831,6 +833,15 @@ do_port_use_buffers(struct impl *impl,
 		spa_log_debug(this->log, "%p: buffer %d %d %d %d", this, i, mb[i].mem_id,
 				mb[i].offset, mb[i].size);
 
+		struct stat sb;
+		if (fstat(m->fd, &sb) == 0) {
+			spa_log_warn(this->log, "%p: buffer %d %u %u %u on file %" PRIu64 ":%" PRIu64 " with size %" PRId64,
+				this, i, mb[i].mem_id, mb[i].offset, mb[i].size, sb.st_dev, sb.st_ino, sb.st_size);
+
+			if ((int64_t) mb[i].offset + mb[i].size > (int64_t) sb.st_size)
+				__builtin_trap();
+		}
+
 		b->buffer.n_metas = SPA_MIN(buffers[i]->n_metas, MAX_METAS);
 		for (j = 0; j < b->buffer.n_metas; j++)
 			memcpy(&b->buffer.metas[j], &buffers[i]->metas[j], sizeof(struct spa_meta));
diff --git a/src/modules/module-client-node/remote-node.c b/src/modules/module-client-node/remote-node.c
index 051ab0716..f79d9ca15 100644
--- a/src/modules/module-client-node/remote-node.c
+++ b/src/modules/module-client-node/remote-node.c
@@ -668,6 +668,8 @@ client_node_port_use_buffers(void *_data,
 		off_t offset;
 		struct pw_memmap *mm;
 
+		pw_log_warn("mapping %u+%u from mem id %u", buffers[i].offset, buffers[i].size, buffers[i].mem_id);
+
 		mm = pw_mempool_map_id(data->pool, buffers[i].mem_id,
 				prot, buffers[i].offset, buffers[i].size, NULL);
 		if (mm == NULL) {
diff --git a/src/modules/module-protocol-native/protocol-native.c b/src/modules/module-protocol-native/protocol-native.c
index 1c2d83e4a..f5678f051 100644
--- a/src/modules/module-protocol-native/protocol-native.c
+++ b/src/modules/module-protocol-native/protocol-native.c
@@ -546,11 +546,19 @@ static void core_event_marshal_bound_id(void *data, uint32_t id, uint32_t global
 	pw_protocol_native_end_resource(resource, b);
 }
 
+#include <sys/stat.h>
+
 static void core_event_marshal_add_mem(void *data, uint32_t id, uint32_t type, int fd, uint32_t flags)
 {
 	struct pw_resource *resource = data;
 	struct spa_pod_builder *b;
 
+	struct stat sb;
+	if (fstat(fd, &sb) == 0) {
+		pw_log_warn("%p: add mem id %u file %" PRIu64 ":%" PRIu64 " with size %" PRId64,
+			resource, id, sb.st_dev, sb.st_ino, sb.st_size);
+	}
+
 	b = pw_protocol_native_begin_resource(resource, PW_CORE_EVENT_ADD_MEM, NULL);
 
 	spa_pod_builder_add_struct(b,
diff --git a/src/pipewire/core.c b/src/pipewire/core.c
index dd7e05eac..32fbbb5ad 100644
--- a/src/pipewire/core.c
+++ b/src/pipewire/core.c
@@ -94,6 +94,8 @@ static void core_event_bound_id(void *data, uint32_t id, uint32_t global_id)
 	}
 }
 
+#include <sys/stat.h>
+
 static void core_event_add_mem(void *data, uint32_t id, uint32_t type, int fd, uint32_t flags)
 {
 	struct pw_core *this = data;
@@ -101,6 +103,12 @@ static void core_event_add_mem(void *data, uint32_t id, uint32_t type, int fd, u
 
 	pw_log_debug("%p: add mem %u type:%u fd:%d flags:%u", this, id, type, fd, flags);
 
+	struct stat sb;
+	if (fstat(fd, &sb) == 0) {
+		pw_log_warn("%p: add mem id %u file %" PRIu64 ":%" PRIu64 " with size %" PRId64,
+			this, id, sb.st_dev, sb.st_ino, sb.st_size);
+	}
+
 	m = pw_mempool_import(this->pool, flags, type, fd);
 	if (m->id != id) {
 		pw_log_error("%p: invalid mem id %u, fd:%d expected %u",
diff --git a/src/pipewire/mem.c b/src/pipewire/mem.c
index ae9e1e46c..5ee2e78d6 100644
--- a/src/pipewire/mem.c
+++ b/src/pipewire/mem.c
@@ -111,6 +111,9 @@ struct memblock {
 	struct spa_list link;		/* link in mempool */
 	struct spa_list mappings;	/* list of struct mapping */
 	struct spa_list memmaps;	/* list of struct memmap */
+	uint64_t dev, ino;
+	struct memblock *import_source;
+	int import_ref;
 };
 
 /* a mapped region of a block */
@@ -354,6 +357,8 @@ static void mapping_unmap(struct mapping *m)
 	pw_memblock_unref(&b->this);
 }
 
+#include <sys/stat.h>
+
 SPA_EXPORT
 struct pw_memmap * pw_memblock_map(struct pw_memblock *block,
 		enum pw_memmap_flags flags, uint32_t offset, uint32_t size, uint32_t tag[5])
@@ -364,6 +369,13 @@ struct pw_memmap * pw_memblock_map(struct pw_memblock *block,
 	struct memmap *mm;
 	struct pw_map_range range;
 
+	struct stat sb;
+	spa_assert_se(fstat(b->this.fd, &sb) == 0);
+	pw_log_warn("%p: block %p[%u] mapping %u+%u file=%d/%" PRIu64 ":%" PRIu64 " size=%" PRId64 " type=%u flags=%u",
+		block->pool, block, block->id, offset, size, block->fd, sb.st_dev, sb.st_ino, sb.st_size, b->this.type, b->this.flags);
+	if ((int64_t) offset + size > (int64_t) sb.st_size)
+		__builtin_trap();
+
 	pw_map_range_init(&range, offset, size, p->pagesize);
 
 	m = memblock_find_mapping(b, flags, offset, size);
@@ -548,6 +560,14 @@ struct pw_memblock * pw_mempool_alloc(struct pw_mempool *pool, enum pw_memblock_
 	pw_log_debug("%p: block:%p id:%d type:%u size:%zu", pool,
 			&b->this, b->this.id, type, size);
 
+	struct stat sb;
+	spa_assert_se(fstat(b->this.fd, &sb) == 0);
+	pw_log_warn("%p: block %p[%u] file=%d/%" PRIu64 ":%" PRIu64 " size=%" PRId64 "type=%u flags=%u",
+		pool, &b->this, b->this.id, b->this.fd, sb.st_dev, sb.st_ino, sb.st_size, type, flags);
+
+	b->dev = sb.st_dev;
+	b->ino = sb.st_ino;
+
 	if (!SPA_FLAG_IS_SET(flags, PW_MEMBLOCK_FLAG_DONT_NOTIFY))
 		pw_mempool_emit_added(impl, &b->this);
 
@@ -571,6 +591,12 @@ static struct memblock * mempool_find_fd(struct pw_mempool *pool, int fd)
 		if (fd == b->this.fd) {
 			pw_log_debug("%p: found %p id:%u fd:%d ref:%d",
 					pool, &b->this, b->this.id, fd, b->this.ref);
+
+			struct stat sb;
+			spa_assert_se(fstat(fd, &sb) == 0);
+			if (b->dev != sb.st_dev || b->ino != sb.st_ino)
+				__builtin_trap();
+
 			return b;
 		}
 	}
@@ -608,6 +634,14 @@ struct pw_memblock * pw_mempool_import(struct pw_mempool *pool,
 	pw_log_debug("%p: block:%p id:%u flags:%08x type:%u fd:%d",
 			pool, b, b->this.id, flags, type, fd);
 
+	struct stat sb;
+	spa_assert_se(fstat(fd, &sb) == 0);
+	pw_log_warn("%p: block %p[%u]: imported file=%d/%" PRIu64 ":%" PRIu64 " size=%" PRId64 " type=%u flags=%u",
+			pool, &b->this, b->this.id, fd, sb.st_dev, sb.st_ino, sb.st_size, type, flags);
+
+	b->dev = sb.st_dev;
+	b->ino = sb.st_ino;
+
 	if (!SPA_FLAG_IS_SET(flags, PW_MEMBLOCK_FLAG_DONT_NOTIFY))
 		pw_mempool_emit_added(impl, &b->this);
 
@@ -620,9 +654,19 @@ struct pw_memblock * pw_mempool_import_block(struct pw_mempool *pool,
 {
 	pw_log_debug("%p: import block:%p type:%d fd:%d", pool,
 			mem, mem->type, mem->fd);
-	return pw_mempool_import(pool,
+
+	struct pw_memblock *res = pw_mempool_import(pool,
 			mem->flags | PW_MEMBLOCK_FLAG_DONT_CLOSE,
 			mem->type, mem->fd);
+	if (res) {
+		struct memblock *r = SPA_CONTAINER_OF(res, struct memblock, this);
+		struct memblock *m = SPA_CONTAINER_OF(mem, struct memblock, this);
+
+		m->import_source = r;
+		r->import_ref += 1;
+	}
+
+	return res;
 }
 
 SPA_EXPORT
@@ -715,6 +759,12 @@ void pw_memblock_free(struct pw_memblock *block)
 	pw_log_debug("%p: block:%p id:%d fd:%d ref:%d",
 			pool, block, block->id, block->fd, block->ref);
 
+	if (b->import_ref)
+		__builtin_trap();
+
+	if (b->import_source)
+		b->import_source->import_ref -= 1;
+
 	block->ref++;
 	if (block->map)
 		block->ref++;
@@ -736,6 +786,7 @@ void pw_memblock_free(struct pw_memblock *block)
 
 	if (block->fd != -1 && !(block->flags & PW_MEMBLOCK_FLAG_DONT_CLOSE)) {
 		pw_log_debug("%p: close fd:%d", pool, block->fd);
+		pw_log_warn("%p: block %p[%u] closing fd=%d", pool, block, block->id, block->fd);
 		close(block->fd);
 	}
 	free(b);

pipewire traps here after starting a pulseaudio here:

Thread 1 "pipewire" received signal SIGILL, Illegal instruction.
pw_memblock_free (block=0x60c000021dc0) at ../src/pipewire/mem.c:763
763			__builtin_trap();
(gdb) bt
#0  pw_memblock_free (block=0x60c000021dc0) at ../src/pipewire/mem.c:763
#1  0x00007ffff6df18d5 in pw_memblock_unref (mem=0x60c000021dc0) at ../src/pipewire/mem.h:148
#2  0x00007ffff6df565c in mapping_unmap (m=0x6040000398d0) at ../src/pipewire/mem.c:357
#3  0x00007ffff6df7aff in pw_memmap_free (map=0x607000128b00) at ../src/pipewire/mem.c:453
#4  0x00007ffff1d8f9ad in do_port_set_io (impl=0x617000002700, direction=SPA_DIRECTION_OUTPUT, port_id=1, mix_id=0, id=1, data=0x0, size=0) at ../src/modules/module-client-node/client-node.c:709
#5  0x00007ffff1dac4e0 in impl_mix_port_set_io (object=0x61d00006b580, direction=SPA_DIRECTION_OUTPUT, mix_id=0, id=1, data=0x0, size=0) at ../src/modules/module-client-node/client-node.c:1513
#6  0x00007ffff6dbf944 in port_set_io (this=0x619000036680, port=0x61d00006ae80, id=1, data=0x0, size=0, mix=0x6190000367e8) at ../src/pipewire/impl-link.c:441
#7  0x00007ffff6dcbe89 in pw_impl_link_deactivate (this=0x619000036680) at ../src/pipewire/impl-link.c:844
#8  0x00007ffff6e1c11e in node_deactivate (this=0x61d000069a80) at ../src/pipewire/impl-node.c:212
#9  0x00007ffff6e1c9b3 in idle_node (this=0x61d000069a80) at ../src/pipewire/impl-node.c:232
#10 0x00007ffff6e57fd9 in pw_impl_node_set_state (node=0x61d000069a80, state=PW_NODE_STATE_SUSPENDED) at ../src/pipewire/impl-node.c:2261
#11 0x00007ffff6d1549b in ensure_state (node=0x61d000069a80, running=false) at ../src/pipewire/context.c:794
#12 0x00007ffff6d1876c in remove_from_driver (context=0x61a000000c80, nodes=0x7fffffffb830) at ../src/pipewire/context.c:900
#13 0x00007ffff6d1c3f8 in pw_context_recalc_graph (context=0x61a000000c80, reason=0x7ffff7058aa0 "node deactivate") at ../src/pipewire/context.c:1106
#14 0x00007ffff6e5910d in pw_impl_node_set_active (node=0x61d000069a80, active=false) at ../src/pipewire/impl-node.c:2291
#15 0x00007ffff1d9d2e0 in client_node_set_active (data=0x617000002700, active=false) at ../src/modules/module-client-node/client-node.c:1044
#16 0x00007ffff1dd0725 in client_node_demarshal_set_active (object=0x60e00005aa20, msg=0x606000057d48) at ../src/modules/module-client-node/protocol-native.c:1105
#17 0x00007ffff32ecd05 in process_messages (data=0x61600000e028) at ../src/modules/module-protocol-native.c:360
#18 0x00007ffff32ee602 in connection_data (data=0x61600000e028, fd=96, mask=1) at ../src/modules/module-protocol-native.c:431
#19 0x00007ffff36c6fd1 in source_io_func (source=0x60800000f320) at ../spa/plugins/support/loop.c:464
#20 0x00007ffff36c6350 in loop_iterate (object=0x62d00000a428, timeout=-1) at ../spa/plugins/support/loop.c:452
#21 0x00007ffff6def359 in pw_main_loop_run (loop=0x60300000b260) at ../src/pipewire/main-loop.c:148
#22 0x0000555555559723 in main (argc=0, argv=0x7ffff7023be0) at ../src/daemon/pipewire.c:131

But even if the import reference counting is removed, I am able to run into the trap instruction by doing the following:

  1. open pavucontrol
  2. start playing audio (I used youtube on firefox)
  3. pactl load-module module-roc-sink-input
  4. pactl load-module module-roc-sink remote_ip=127.0.0.1
  5. starts switching the target of the firefox audio stream randomly back and forth

Then it stops with the following output:

[I][54106.063116] pw.link      | [     impl-link.c:  114 link_update_state()] (95.0 -> 100.0) paused -> init
[I][54106.063149] pw.context   | [       context.c: 1010 pw_context_recalc_graph()] 0x61a000000c80: busy:0 reason:link unprepared
[D][54106.063305] pw.mem       | [           mem.c:  849 pw_mempool_find_tag()] 0x60800000f2a0: find tag 95:1:1:1:1 size:20
[D][54106.063360] pw.mem       | [           mem.c:  807 pw_mempool_find_ptr()] 0x608000001120: block:0x60c00002e900 id:27 for 0x7fffdcf0e008
[D][54106.063392] pw.mem       | [           mem.c:  655 pw_mempool_import_block()] 0x60800000f2a0: import block:0x60c00002e900 type:2 fd:106
[D][54106.063436] pw.mem       | [           mem.c:  634 pw_mempool_import()] 0x60800000f2a0: block:0x60c00000f280 id:2 flags:0000001f type:2 fd:106
[W][54106.063480] pw.mem       | [           mem.c:  639 pw_mempool_import()] 0x60800000f2a0: block 0x60c00000f280[2]: imported file=106/1:185090 size=16384 type=2 flags=31
[W][54106.063527] mod.protocol-native | [protocol-native.:  558 core_event_marshal_add_mem()] 0x61100003e200: add mem id 2 file 1:185090 with size 16384
[D][54106.063590] pw.mem       | [           mem.c:  706 pw_mempool_import_map()] 0x60800000f2a0: mapping:0x60400003c990 block:0x60c00000f280 offset:0 size:16384 ref:1
[W][54106.063632] pw.mem       | [           mem.c:  374 pw_memblock_map()] 0x60800000f2a0: block 0x60c00000f280[2] mapping 8+8 file=106/1:185090 size=16384 type=2 flags=31
[D][54106.063672] pw.mem       | [           mem.c:  269 memblock_find_mapping()] 0x60800000f2a0: check 0x60400003c990 offset:(0 <= 8) end:(16384 >= 16)
[D][54106.063707] pw.mem       | [           mem.c:  273 memblock_find_mapping()] 0x60800000f2a0: found 0x60c00000f280 id:2 fd:106 offs:8 size:8 ref:1
[D][54106.063749] pw.mem       | [           mem.c:  402 pw_memblock_map()] 0x60800000f2a0: map:0x60700012a930 block:0x60c00000f280 fd:106 ptr:0x7fffdcf0e008 (8 8) mapping:0x60400003c990 ref:1
[D][54106.063787] pw.mem       | [           mem.c:  407 pw_memblock_map()] 0x60800000f2a0: tag:95:1:1:1:1
[D][54106.063852] pw.mem       | [           mem.c:  719 pw_mempool_import_map()] 0x60800000f2a0: from pool:0x608000001120 block:0x60c00000f280 id:2 data:0x7fffdcf0e008 size:8 ref:1
[D][54106.063926] pw.mem       | [           mem.c:  849 pw_mempool_find_tag()] 0x60800000d6a0: find tag 100:0:1:0:1 size:20
[D][54106.063963] pw.mem       | [           mem.c:  807 pw_mempool_find_ptr()] 0x608000001120: block:0x60c00002e900 id:27 for 0x7fffdcf0e008
[D][54106.063984] pw.mem       | [           mem.c:  655 pw_mempool_import_block()] 0x60800000d6a0: import block:0x60c00002e900 type:2 fd:106
[D][54106.064014] pw.mem       | [           mem.c:  634 pw_mempool_import()] 0x60800000d6a0: block:0x60c00000f340 id:18 flags:0000001f type:2 fd:106
[W][54106.064041] pw.mem       | [           mem.c:  639 pw_mempool_import()] 0x60800000d6a0: block 0x60c00000f340[18]: imported file=106/1:185090 size=16384 type=2 flags=31
[W][54106.064072] mod.protocol-native | [protocol-native.:  558 core_event_marshal_add_mem()] 0x611000026600: add mem id 18 file 1:185090 with size 16384
[D][54106.064112] pw.mem       | [           mem.c:  706 pw_mempool_import_map()] 0x60800000d6a0: mapping:0x60400003c9d0 block:0x60c00000f340 offset:0 size:16384 ref:1
[W][54106.064140] pw.mem       | [           mem.c:  374 pw_memblock_map()] 0x60800000d6a0: block 0x60c00000f340[18] mapping 8+8 file=106/1:185090 size=16384 type=2 flags=31
[D][54106.064167] pw.mem       | [           mem.c:  269 memblock_find_mapping()] 0x60800000d6a0: check 0x60400003c9d0 offset:(0 <= 8) end:(16384 >= 16)
[D][54106.064191] pw.mem       | [           mem.c:  273 memblock_find_mapping()] 0x60800000d6a0: found 0x60c00000f340 id:18 fd:106 offs:8 size:8 ref:1
[D][54106.064217] pw.mem       | [           mem.c:  402 pw_memblock_map()] 0x60800000d6a0: map:0x60700012a9a0 block:0x60c00000f340 fd:106 ptr:0x7fffdcf0e008 (8 8) mapping:0x60400003c9d0 ref:1
[D][54106.064242] pw.mem       | [           mem.c:  407 pw_memblock_map()] 0x60800000d6a0: tag:100:0:1:0:1
[D][54106.064265] pw.mem       | [           mem.c:  719 pw_mempool_import_map()] 0x60800000d6a0: from pool:0x608000001120 block:0x60c00000f340 id:18 data:0x7fffdcf0e008 size:8 ref:1
[I][54106.064312] pw.link      | [     impl-link.c:  643 pw_impl_link_activate()] (95.1 -> 100.1) activated
[I][54106.064335] pw.link      | [     impl-link.c:  114 link_update_state()] (95.1 -> 100.1) paused -> active
[D][54106.064441] pw.mem       | [           mem.c:  759 pw_memblock_free()] 0x60800000f2a0: block:0x60c00002f380 id:4 fd:135 ref:0
[D][54106.064491] pw.mem       | [           mem.c:  759 pw_memblock_free()] 0x608000001120: block:0x60c00002f2c0 id:24 fd:135 ref:0
[D][54106.064515] pw.mem       | [           mem.c:  447 pw_memmap_free()] 0x608000001120: map:0x60700012a460 block:0x60c00002f2c0 fd:135 ptr:0x7fffdc3f0000 mapping:0x60400003c010 ref:1
[D][54106.064540] pw.mem       | [           mem.c:  354 mapping_unmap()] 0x608000001120: mapping:0x60400003c010 block:0x60c00002f2c0 fd:135 ptr:0x7fffdc3f0000 size:69632 block-ref:2
[D][54106.064565] pw.mem       | [           mem.c:  341 mapping_free()] 0x608000001120: mapping:0x60400003c010 block:0x60c00002f2c0 fd:135 ptr:0x7fffdc3f0000 size:69632 block-ref:2
[D][54106.064609] pw.mem       | [           mem.c:  790 pw_memblock_free()] 0x608000001120: close fd:135
[W][54106.064630] pw.mem       | [           mem.c:  791 pw_memblock_free()] 0x608000001120: block 0x60c00002f2c0[24] closing fd=135
[I][54106.064663] pw.link      | [     impl-link.c:  114 link_update_state()] (95.1 -> 100.1) active -> init
[I][54106.064792] pw.node      | [     impl-node.c:  410 node_update_state()] (Firefox-95) running -> suspended
[I][54106.065122] pw.link      | [     impl-link.c:  114 link_update_state()] (95.0 -> 100.0) init -> negotiating
[I][54106.071021] pw.link      | [     impl-link.c: 1419 pw_impl_link_destroy()] (95.0 -> 100.0) destroy
[D][54106.071061] pw.mem       | [           mem.c:  592 mempool_find_fd()] 0x60800000f2a0: found 0x60c00000e140 id:1 fd:103 ref:2
[I][54106.073014] pw.port      | [     impl-port.c: 1403 pw_impl_port_recalc_latency()] port 103: keep output latency 0,000000-0,000000 0-0 0-0
[D][54106.073070] pw.mem       | [           mem.c:  759 pw_memblock_free()] 0x60800000d6a0: block:0x60c00000e980 id:17 fd:107 ref:0
[I][54106.073627] pw.link      | [     impl-link.c: 1419 pw_impl_link_destroy()] (95.1 -> 100.1) destroy
[D][54106.073720] pw.mem       | [           mem.c:  849 pw_mempool_find_tag()] 0x60800000d6a0: find tag 100:0:1:0:1 size:20
[D][54106.073748] pw.mem       | [           mem.c:  855 pw_mempool_find_tag()] 0x60800000d6a0: found 0x60700012a9a0
[D][54106.073767] pw.mem       | [           mem.c:  447 pw_memmap_free()] 0x60800000d6a0: map:0x60700012a9a0 block:0x60c00000f340 fd:106 ptr:0x7fffdcf0e008 mapping:0x60400003c9d0 ref:1
[D][54106.073782] pw.mem       | [           mem.c:  354 mapping_unmap()] 0x60800000d6a0: mapping:0x60400003c9d0 block:0x60c00000f340 fd:106 ptr:0x7fffdcf0e000 size:16384 block-ref:1
[D][54106.073797] pw.mem       | [           mem.c:  341 mapping_free()] 0x60800000d6a0: mapping:0x60400003c9d0 block:0x60c00000f340 fd:106 ptr:0x7fffdcf0e000 size:16384 block-ref:1
[D][54106.073851] pw.mem       | [           mem.c:  759 pw_memblock_free()] 0x60800000d6a0: block:0x60c00000f340 id:18 fd:106 ref:0
[I][54106.073890] pw.link      | [     impl-link.c:  851 pw_impl_link_deactivate()] (95.1 -> 100.1) deactivated
[I][54106.073907] pw.link      | [     impl-link.c:  114 link_update_state()] (95.1 -> 100.1) init -> paused
[I][54106.073960] pw.context   | [       context.c: 1010 pw_context_recalc_graph()] 0x61a000000c80: busy:0 reason:link prepared
[W][54106.074284] pw.link      | [     impl-link.c:  448 port_set_io()] 0x61900005f080: port 0x61d00007d080 can't set io:1 (Spa:Enum:IO:Buffers): Érvénytelen argumentum
[W][54106.074344] pw.link      | [     impl-link.c:  448 port_set_io()] 0x61900005f080: port 0x61d00007d080 can't set io:1 (Spa:Enum:IO:Buffers): Érvénytelen argumentum
[D][54106.074384] pw.mem       | [           mem.c:  592 mempool_find_fd()] 0x60800000f2a0: found 0x60c00000e140 id:1 fd:103 ref:1
[D][54106.074413] pw.mem       | [           mem.c:  759 pw_memblock_free()] 0x60800000f2a0: block:0x60c00000e140 id:1 fd:103 ref:0
[I][54106.075304] pw.port      | [     impl-port.c: 1403 pw_impl_port_recalc_latency()] port 101: keep output latency 0,000000-0,000000 0-0 0-0
[D][54106.075337] pw.mem       | [           mem.c:  759 pw_memblock_free()] 0x60800000d6a0: block:0x60c00000ea40 id:16 fd:135 ref:0
[I][54106.075437] pw.context   | [       context.c: 1010 pw_context_recalc_graph()] 0x61a000000c80: busy:0 reason:link destroy
[I][54106.075484] pw.node      | [     impl-node.c:  858 pw_impl_node_set_driver()] move quantum:1024 rate:44100 (alsa_input.pci-0000_00_1f.3.analog-stereo-57 -> Firefox-95)
[I][54106.075502] pw.node      | [     impl-node.c:  876 pw_impl_node_set_driver()] (Firefox-95) -> change driver (alsa_input.pci-0000_00_1f.3.analog-stereo-57 -> Firefox-95)
[D][54106.075518] pw.mem       | [           mem.c:  849 pw_mempool_find_tag()] 0x60800000f2a0: find tag 95:7:0:0:0 size:20
[D][54106.075534] pw.mem       | [           mem.c:  855 pw_mempool_find_tag()] 0x60800000f2a0: found 0x60700012a4d0
[D][54106.075552] pw.mem       | [           mem.c:  807 pw_mempool_find_ptr()] 0x608000001120: block:0x60c00000d900 id:22 for 0x7fffdd16e230
[D][54106.075565] pw.mem       | [           mem.c:  655 pw_mempool_import_block()] 0x60800000f2a0: import block:0x60c00000d900 type:2 fd:98
[D][54106.075578] pw.mem       | [           mem.c:  592 mempool_find_fd()] 0x60800000f2a0: found 0x60c00000df00 id:0 fd:98 ref:2
[W][54106.075601] pw.mem       | [           mem.c:  374 pw_memblock_map()] 0x60800000f2a0: block 0x60c00000df00[0] mapping 560+1688 file=98/1:185083 size=2312 type=2 flags=31
[D][54106.075619] pw.mem       | [           mem.c:  269 memblock_find_mapping()] 0x60800000f2a0: check 0x6040000395d0 offset:(0 <= 560) end:(4096 >= 2248)
[D][54106.075633] pw.mem       | [           mem.c:  273 memblock_find_mapping()] 0x60800000f2a0: found 0x60c00000df00 id:0 fd:98 offs:560 size:1688 ref:2
[D][54106.075651] pw.mem       | [           mem.c:  402 pw_memblock_map()] 0x60800000f2a0: map:0x60700012ab60 block:0x60c00000df00 fd:98 ptr:0x7fffdd169230 (560 1688) mapping:0x6040000395d0 ref:2
[D][54106.075666] pw.mem       | [           mem.c:  407 pw_memblock_map()] 0x60800000f2a0: tag:95:7:0:0:0
[D][54106.075678] pw.mem       | [           mem.c:  719 pw_mempool_import_map()] 0x60800000f2a0: from pool:0x608000001120 block:0x60c00000df00 id:0 data:0x7fffdd16e230 size:1688 ref:2
[D][54106.075693] pw.mem       | [           mem.c:  447 pw_memmap_free()] 0x60800000f2a0: map:0x60700012a4d0 block:0x60c00002fec0 fd:61 ptr:0x7fffe4eec230 mapping:0x60400003c750 ref:1
[D][54106.075707] pw.mem       | [           mem.c:  354 mapping_unmap()] 0x60800000f2a0: mapping:0x60400003c750 block:0x60c00002fec0 fd:61 ptr:0x7fffe4eec000 size:2312 block-ref:2
[D][54106.075721] pw.mem       | [           mem.c:  341 mapping_free()] 0x60800000f2a0: mapping:0x60400003c750 block:0x60c00002fec0 fd:61 ptr:0x7fffe4eec000 size:2312 block-ref:2
[D][54106.075849] pw.mem       | [           mem.c:  592 mempool_find_fd()] 0x60800000f2a0: found 0x60c00002fec0 id:3 fd:61 ref:1
[D][54106.075909] pw.mem       | [           mem.c:  759 pw_memblock_free()] 0x60800000f2a0: block:0x60c00002fec0 id:3 fd:61 ref:0
[I][54106.076108] pw.node      | [     impl-node.c:  876 pw_impl_node_set_driver()] (PulseAudio hangerőszabályzó-100) -> change driver (alsa_input.pci-0000_00_1f.3.analog-stereo-57 -> PulseAudio hangerőszabályzó-100)
[D][54106.076145] pw.mem       | [           mem.c:  849 pw_mempool_find_tag()] 0x60800000d6a0: find tag 100:7:0:0:0 size:20
[D][54106.076175] pw.mem       | [           mem.c:  855 pw_mempool_find_tag()] 0x60800000d6a0: found 0x60700012a700
[D][54106.076194] pw.mem       | [           mem.c:  807 pw_mempool_find_ptr()] 0x608000001120: block:0x60c00002d640 id:26 for 0x7fffdcf12230
[D][54106.076208] pw.mem       | [           mem.c:  655 pw_mempool_import_block()] 0x60800000d6a0: import block:0x60c00002d640 type:2 fd:103
[D][54106.076223] pw.mem       | [           mem.c:  592 mempool_find_fd()] 0x60800000d6a0: found 0x60c00002e9c0 id:15 fd:103 ref:2
[W][54106.076249] pw.mem       | [           mem.c:  374 pw_memblock_map()] 0x60800000d6a0: block 0x60c00002e9c0[15] mapping 560+1688 file=103/1:183270 size=2312 type=2 flags=31
[D][54106.076317] pw.mem       | [           mem.c:  269 memblock_find_mapping()] 0x60800000d6a0: check 0x60400003bf90 offset:(0 <= 560) end:(4096 >= 2248)
[D][54106.076370] pw.mem       | [           mem.c:  273 memblock_find_mapping()] 0x60800000d6a0: found 0x60c00002e9c0 id:15 fd:103 offs:560 size:1688 ref:2
[D][54106.076405] pw.mem       | [           mem.c:  402 pw_memblock_map()] 0x60800000d6a0: map:0x60700012abd0 block:0x60c00002e9c0 fd:103 ptr:0x7fffdcf0d230 (560 1688) mapping:0x60400003bf90 ref:2
[D][54106.076426] pw.mem       | [           mem.c:  407 pw_memblock_map()] 0x60800000d6a0: tag:100:7:0:0:0
[D][54106.076446] pw.mem       | [           mem.c:  719 pw_mempool_import_map()] 0x60800000d6a0: from pool:0x608000001120 block:0x60c00002e9c0 id:15 data:0x7fffdcf12230 size:1688 ref:2
[D][54106.076811] pw.mem       | [           mem.c:  447 pw_memmap_free()] 0x60800000d6a0: map:0x60700012a700 block:0x60c00000d0c0 fd:61 ptr:0x7fffe4eec230 mapping:0x604000039350 ref:3
[D][54106.076997] pw.mem       | [           mem.c:  592 mempool_find_fd()] 0x60800000d6a0: found 0x60c00000d0c0 id:13 fd:61 ref:4
[I][54106.079541] pw.context   | [       context.c: 1010 pw_context_recalc_graph()] 0x61a000000c80: busy:0 reason:node deactivate
[I][54106.079774] pw.node      | [     impl-node.c: 1874 pw_impl_node_destroy()] (PulseAudio hangerőszabályzó-100) destroy
[I][54106.079945] pw.node      | [     impl-node.c:  410 node_update_state()] (PulseAudio hangerőszabályzó-100) running -> suspended
[D][54106.080547] pw.mem       | [           mem.c:  849 pw_mempool_find_tag()] 0x60800000d6a0: find tag 100:0:0:0:0 size:4
[D][54106.080588] pw.mem       | [           mem.c:  855 pw_mempool_find_tag()] 0x60800000d6a0: found 0x60700012a380
[D][54106.080610] pw.mem       | [           mem.c:  447 pw_memmap_free()] 0x60800000d6a0: map:0x60700012a380 block:0x60c00002e9c0 fd:103 ptr:0x7fffdcf0d230 mapping:0x60400003bf90 ref:2
[D][54106.080639] pw.mem       | [           mem.c:  849 pw_mempool_find_tag()] 0x60800000d6a0: find tag 100:0:0:0:0 size:4
[D][54106.080667] pw.mem       | [           mem.c:  855 pw_mempool_find_tag()] 0x60800000d6a0: found 0x60700012abd0
[D][54106.080685] pw.mem       | [           mem.c:  447 pw_memmap_free()] 0x60800000d6a0: map:0x60700012abd0 block:0x60c00002e9c0 fd:103 ptr:0x7fffdcf0d230 mapping:0x60400003bf90 ref:1
[D][54106.080709] pw.mem       | [           mem.c:  354 mapping_unmap()] 0x60800000d6a0: mapping:0x60400003bf90 block:0x60c00002e9c0 fd:103 ptr:0x7fffdcf0d000 size:4096 block-ref:2
[D][54106.080733] pw.mem       | [           mem.c:  341 mapping_free()] 0x60800000d6a0: mapping:0x60400003bf90 block:0x60c00002e9c0 fd:103 ptr:0x7fffdcf0d000 size:4096 block-ref:2
[D][54106.080775] pw.mem       | [           mem.c:  849 pw_mempool_find_tag()] 0x60800000d6a0: find tag 100:0:0:0:0 size:4
[D][54106.080804] pw.mem       | [           mem.c:  759 pw_memblock_free()] 0x60800000d6a0: block:0x60c00002e9c0 id:15 fd:103 ref:0
[D][54106.080839] pw.mem       | [           mem.c:  759 pw_memblock_free()] 0x608000001120: block:0x60c00002e900 id:27 fd:106 ref:0
[D][54106.080861] pw.mem       | [           mem.c:  447 pw_memmap_free()] 0x608000001120: map:0x60700012a2a0 block:0x60c00002e900 fd:106 ptr:0x7fffdcf0e000 mapping:0x60400003bf50 ref:1
[D][54106.080884] pw.mem       | [           mem.c:  354 mapping_unmap()] 0x608000001120: mapping:0x60400003bf50 block:0x60c00002e900 fd:106 ptr:0x7fffdcf0e000 size:16384 block-ref:2
[D][54106.080908] pw.mem       | [           mem.c:  341 mapping_free()] 0x608000001120: mapping:0x60400003bf50 block:0x60c00002e900 fd:106 ptr:0x7fffdcf0e000 size:16384 block-ref:2
[D][54106.080949] pw.mem       | [           mem.c:  790 pw_memblock_free()] 0x608000001120: close fd:106
[W][54106.080969] pw.mem       | [           mem.c:  791 pw_memblock_free()] 0x608000001120: block 0x60c00002e900[27] closing fd=106
[D][54106.081015] pw.mem       | [           mem.c:  759 pw_memblock_free()] 0x608000001120: block:0x60c00002d640 id:26 fd:103 ref:0
[D][54106.081038] pw.mem       | [           mem.c:  447 pw_memmap_free()] 0x608000001120: map:0x60700012a230 block:0x60c00002d640 fd:103 ptr:0x7fffdcf12000 mapping:0x60400003bd90 ref:1
[D][54106.081061] pw.mem       | [           mem.c:  354 mapping_unmap()] 0x608000001120: mapping:0x60400003bd90 block:0x60c00002d640 fd:103 ptr:0x7fffdcf12000 size:4096 block-ref:2
[D][54106.081084] pw.mem       | [           mem.c:  341 mapping_free()] 0x608000001120: mapping:0x60400003bd90 block:0x60c00002d640 fd:103 ptr:0x7fffdcf12000 size:4096 block-ref:2
[D][54106.081123] pw.mem       | [           mem.c:  790 pw_memblock_free()] 0x608000001120: close fd:103
[W][54106.081142] pw.mem       | [           mem.c:  791 pw_memblock_free()] 0x608000001120: block 0x60c00002d640[26] closing fd=103
[D][54106.081495] pw.mem       | [           mem.c:  532 pw_mempool_alloc()] 0x608000001120: new fd:103
[W][54106.081538] pw.mem       | [           mem.c:  374 pw_memblock_map()] 0x608000001120: block 0x60c00000fb80[0] mapping 0+2312 file=103/1:191646 size=2312 type=2 flags=15
[D][54106.081584] pw.mem       | [           mem.c:  330 memblock_map()] 0x608000001120: block:0x60c00000fb80 fd:103 map:0x60400003d050 ptr:0x7fffdcf12000 (0 4096) block-ref:2
[D][54106.081609] pw.mem       | [           mem.c:  402 pw_memblock_map()] 0x608000001120: map:0x60700012ac40 block:0x60c00000fb80 fd:103 ptr:0x7fffdcf12000 (0 2312) mapping:0x60400003d050 ref:1
[D][54106.081635] pw.mem       | [           mem.c:  560 pw_mempool_alloc()] 0x608000001120: block:0x60c00000fb80 id:26 type:2 size:2312
[W][54106.081661] pw.mem       | [           mem.c:  565 pw_mempool_alloc()] 0x608000001120: block 0x60c00000fb80[26] file=103/1:191646 size=2312type=2 flags=15
[I][54106.081774] pw.node      | [     impl-node.c:  963 check_properties()] (PulseAudio hangerőszabályzó-0) latency:0/0 -> 1/25
[I][54106.081814] pw.node      | [     impl-node.c:  996 check_properties()] (PulseAudio hangerőszabályzó-0) rate:0/0 -> 1/25
[I][54106.082266] pw.node      | [     impl-node.c:  410 node_update_state()] (Firefox-95) suspended -> idle
[I][54106.085750] pw.link      | [     impl-link.c: 1282 pw_context_create_link()] (95.0 -> 56.0) (Firefox) -> (alsa_output.pci-0000_00_1f.3.analog-stereo)
[I][54106.085792] pw.port      | [     impl-port.c: 1403 pw_impl_port_recalc_latency()] port 96: set input latency 1,000000-1,000000 0-0 0-0
[I][54106.085869] pw.port      | [     impl-port.c: 1403 pw_impl_port_recalc_latency()] port 62: keep output latency 0,000000-0,000000 0-0 0-0
[D][54106.085901] pw.mem       | [           mem.c:  655 pw_mempool_import_block()] 0x60800000f2a0: import block:0x60c000009400 type:2 fd:59
[D][54106.085933] pw.mem       | [           mem.c:  634 pw_mempool_import()] 0x60800000f2a0: block:0x60c000030640 id:3 flags:0000001f type:2 fd:59
[W][54106.085965] pw.mem       | [           mem.c:  639 pw_mempool_import()] 0x60800000f2a0: block 0x60c000030640[3]: imported file=59/1:189806 size=2312 type=2 flags=31
[W][54106.085996] mod.protocol-native | [protocol-native.:  558 core_event_marshal_add_mem()] 0x61100003e200: add mem id 3 file 1:189806 with size 2312
[I][54106.086857] pw.link      | [     impl-link.c: 1282 pw_context_create_link()] (95.1 -> 56.1) (Firefox) -> (alsa_output.pci-0000_00_1f.3.analog-stereo)
[I][54106.086893] pw.port      | [     impl-port.c: 1403 pw_impl_port_recalc_latency()] port 98: set input latency 1,000000-1,000000 0-0 0-0
[I][54106.086952] pw.port      | [     impl-port.c: 1403 pw_impl_port_recalc_latency()] port 64: keep output latency 0,000000-0,000000 0-0 0-0
[D][54106.086980] pw.mem       | [           mem.c:  655 pw_mempool_import_block()] 0x60800000f2a0: import block:0x60c000009400 type:2 fd:59
[D][54106.087004] pw.mem       | [           mem.c:  592 mempool_find_fd()] 0x60800000f2a0: found 0x60c000030640 id:3 fd:59 ref:1
[D][54106.087701] pw.mem       | [           mem.c:  532 pw_mempool_alloc()] 0x608000001120: new fd:134
[W][54106.087740] pw.mem       | [           mem.c:  374 pw_memblock_map()] 0x608000001120: block 0x60c000030940[0] mapping 0+16384 file=134/1:191647 size=16384 type=2 flags=15
[D][54106.087787] pw.mem       | [           mem.c:  330 memblock_map()] 0x608000001120: block:0x60c000030940 fd:134 map:0x60400003d090 ptr:0x7fffdcf0e000 (0 16384) block-ref:2
[D][54106.087810] pw.mem       | [           mem.c:  402 pw_memblock_map()] 0x608000001120: map:0x60700012acb0 block:0x60c000030940 fd:134 ptr:0x7fffdcf0e000 (0 16384) mapping:0x60400003d090 ref:1
[D][54106.087837] pw.mem       | [           mem.c:  560 pw_mempool_alloc()] 0x608000001120: block:0x60c000030940 id:27 type:2 size:16384
[W][54106.087863] pw.mem       | [           mem.c:  565 pw_mempool_alloc()] 0x608000001120: block 0x60c000030940[27] file=134/1:191647 size=16384type=2 flags=15
[D][54106.087890] pw.mem       | [           mem.c:  655 pw_mempool_import_block()] 0x60800000d6a0: import block:0x60c00000fb80 type:2 fd:103
[D][54106.087917] pw.mem       | [           mem.c:  634 pw_mempool_import()] 0x60800000d6a0: block:0x60c000030a00 id:15 flags:0000001f type:2 fd:103
[W][54106.087942] pw.mem       | [           mem.c:  639 pw_mempool_import()] 0x60800000d6a0: block 0x60c000030a00[15]: imported file=103/1:191646 size=2312 type=2 flags=31
[W][54106.087971] mod.protocol-native | [protocol-native.:  558 core_event_marshal_add_mem()] 0x611000026600: add mem id 15 file 1:191646 with size 2312
[I][54106.088094] pw.node      | [     impl-node.c:  410 node_update_state()] (PulseAudio hangerőszabályzó-106) creating -> suspended
[D][54106.088315] pw.mem       | [           mem.c:  849 pw_mempool_find_tag()] 0x60800000d6a0: find tag 106:7:0:0:0 size:20
[D][54106.088359] pw.mem       | [           mem.c:  807 pw_mempool_find_ptr()] 0x608000001120: block:0x60c00000fb80 id:26 for 0x7fffdcf12230
[D][54106.088379] pw.mem       | [           mem.c:  655 pw_mempool_import_block()] 0x60800000d6a0: import block:0x60c00000fb80 type:2 fd:103
[D][54106.088402] pw.mem       | [           mem.c:  592 mempool_find_fd()] 0x60800000d6a0: found 0x60c000030a00 id:15 fd:103 ref:1
[W][54106.088435] pw.mem       | [           mem.c:  374 pw_memblock_map()] 0x60800000d6a0: block 0x60c000030a00[15] mapping 560+1688 file=103/1:191646 size=2312 type=2 flags=31
[D][54106.088478] pw.mem       | [           mem.c:  330 memblock_map()] 0x60800000d6a0: block:0x60c000030a00 fd:103 map:0x60400003d0d0 ptr:0x7fffdcf0d000 (0 4096) block-ref:2
[D][54106.088503] pw.mem       | [           mem.c:  402 pw_memblock_map()] 0x60800000d6a0: map:0x60700012ad20 block:0x60c000030a00 fd:103 ptr:0x7fffdcf0d230 (560 1688) mapping:0x60400003d0d0 ref:1
[D][54106.088528] pw.mem       | [           mem.c:  407 pw_memblock_map()] 0x60800000d6a0: tag:106:7:0:0:0
[D][54106.088549] pw.mem       | [           mem.c:  719 pw_mempool_import_map()] 0x60800000d6a0: from pool:0x608000001120 block:0x60c000030a00 id:15 data:0x7fffdcf12230 size:1688 ref:2
[D][54106.088586] pw.mem       | [           mem.c:  849 pw_mempool_find_tag()] 0x60800000d6a0: find tag 106:3:0:0:0 size:20
[D][54106.088617] pw.mem       | [           mem.c:  807 pw_mempool_find_ptr()] 0x608000001120: block:0x60c00000fb80 id:26 for 0x7fffdcf12230
[D][54106.088636] pw.mem       | [           mem.c:  655 pw_mempool_import_block()] 0x60800000d6a0: import block:0x60c00000fb80 type:2 fd:103
[D][54106.088659] pw.mem       | [           mem.c:  592 mempool_find_fd()] 0x60800000d6a0: found 0x60c000030a00 id:15 fd:103 ref:2
[W][54106.088689] pw.mem       | [           mem.c:  374 pw_memblock_map()] 0x60800000d6a0: block 0x60c000030a00[15] mapping 560+160 file=103/1:191646 size=2312 type=2 flags=31
[D][54106.088712] pw.mem       | [           mem.c:  269 memblock_find_mapping()] 0x60800000d6a0: check 0x60400003d0d0 offset:(0 <= 560) end:(4096 >= 720)
[D][54106.088735] pw.mem       | [           mem.c:  273 memblock_find_mapping()] 0x60800000d6a0: found 0x60c000030a00 id:15 fd:103 offs:560 size:160 ref:2
[D][54106.088760] pw.mem       | [           mem.c:  402 pw_memblock_map()] 0x60800000d6a0: map:0x60700012ad90 block:0x60c000030a00 fd:103 ptr:0x7fffdcf0d230 (560 160) mapping:0x60400003d0d0 ref:2
[D][54106.088783] pw.mem       | [           mem.c:  407 pw_memblock_map()] 0x60800000d6a0: tag:106:3:0:0:0
[D][54106.088804] pw.mem       | [           mem.c:  719 pw_mempool_import_map()] 0x60800000d6a0: from pool:0x608000001120 block:0x60c000030a00 id:15 data:0x7fffdcf12230 size:160 ref:2
[I][54106.089617] pw.link      | [     impl-link.c:  114 link_update_state()] (95.0 -> 56.0) init -> negotiating
[I][54106.089801] pw.link      | [     impl-link.c:  114 link_update_state()] (95.1 -> 56.1) init -> negotiating
[I][54106.089931] pw.context   | [       context.c: 1010 pw_context_recalc_graph()] 0x61a000000c80: busy:0 reason:node activate
[I][54106.094968] pw.link      | [     impl-link.c:  114 link_update_state()] (95.0 -> 56.0) negotiating -> allocating
[D][54106.095145] pw.mem       | [           mem.c:  532 pw_mempool_alloc()] 0x608000001120: new fd:104
[W][54106.095186] pw.mem       | [           mem.c:  374 pw_memblock_map()] 0x608000001120: block 0x60c0000310c0[0] mapping 0+65664 file=104/1:187830 size=65664 type=2 flags=15
[D][54106.095225] pw.mem       | [           mem.c:  330 memblock_map()] 0x608000001120: block:0x60c0000310c0 fd:104 map:0x60400003d150 ptr:0x7fffdc3f0000 (0 69632) block-ref:2
[D][54106.095245] pw.mem       | [           mem.c:  402 pw_memblock_map()] 0x608000001120: map:0x60700012ae00 block:0x60c0000310c0 fd:104 ptr:0x7fffdc3f0000 (0 65664) mapping:0x60400003d150 ref:1
[D][54106.095262] pw.mem       | [           mem.c:  560 pw_mempool_alloc()] 0x608000001120: block:0x60c0000310c0 id:24 type:2 size:65664
[W][54106.095279] pw.mem       | [           mem.c:  565 pw_mempool_alloc()] 0x608000001120: block 0x60c0000310c0[24] file=104/1:187830 size=65664type=2 flags=15
[D][54106.095318] pw.mem       | [           mem.c:  807 pw_mempool_find_ptr()] 0x608000001120: block:0x60c0000310c0 id:24 for 0x7fffdc3f0000
[D][54106.095336] pw.mem       | [           mem.c:  807 pw_mempool_find_ptr()] 0x608000001120: block:0x60c0000310c0 id:24 for 0x7fffdc3f0040
[D][54106.095349] pw.mem       | [           mem.c:  655 pw_mempool_import_block()] 0x60800000f2a0: import block:0x60c0000310c0 type:2 fd:104
[D][54106.095367] pw.mem       | [           mem.c:  634 pw_mempool_import()] 0x60800000f2a0: block:0x60c000031180 id:1 flags:0000001f type:2 fd:104
[W][54106.095385] pw.mem       | [           mem.c:  639 pw_mempool_import()] 0x60800000f2a0: block 0x60c000031180[1]: imported file=104/1:187830 size=65664 type=2 flags=31
[W][54106.095406] mod.protocol-native | [protocol-native.:  558 core_event_marshal_add_mem()] 0x61100003e200: add mem id 1 file 1:187830 with size 65664
[W][54106.095445][   client-node.c:  838 do_port_use_buffers()] 0x617000002720: buffer 0 1 0 32832 on file 1:187830 with size 65664
[D][54106.095468] pw.mem       | [           mem.c:  807 pw_mempool_find_ptr()] 0x608000001120: block:0x60c0000310c0 id:24 for 0x7fffdc3f8040
[D][54106.095484] pw.mem       | [           mem.c:  807 pw_mempool_find_ptr()] 0x608000001120: block:0x60c0000310c0 id:24 for 0x7fffdc3f8080
[D][54106.095496] pw.mem       | [           mem.c:  655 pw_mempool_import_block()] 0x60800000f2a0: import block:0x60c0000310c0 type:2 fd:104
[D][54106.095509] pw.mem       | [           mem.c:  592 mempool_find_fd()] 0x60800000f2a0: found 0x60c000031180 id:1 fd:104 ref:1
[W][54106.095529][   client-node.c:  838 do_port_use_buffers()] 0x617000002720: buffer 1 1 32832 32832 on file 1:187830 with size 65664
[I][54106.095594] pw.link      | [     impl-link.c:  114 link_update_state()] (95.1 -> 56.1) negotiating -> allocating
[D][54106.095705] pw.mem       | [           mem.c:  532 pw_mempool_alloc()] 0x608000001120: new fd:106
[W][54106.095735] pw.mem       | [           mem.c:  374 pw_memblock_map()] 0x608000001120: block 0x60c000031240[0] mapping 0+65664 file=106/1:187831 size=65664 type=2 flags=15
[D][54106.095767] pw.mem       | [           mem.c:  330 memblock_map()] 0x608000001120: block:0x60c000031240 fd:106 map:0x60400003d190 ptr:0x7fffdbee3000 (0 69632) block-ref:2
[D][54106.095784] pw.mem       | [           mem.c:  402 pw_memblock_map()] 0x608000001120: map:0x60700012ae70 block:0x60c000031240 fd:106 ptr:0x7fffdbee3000 (0 65664) mapping:0x60400003d190 ref:1
[D][54106.095801] pw.mem       | [           mem.c:  560 pw_mempool_alloc()] 0x608000001120: block:0x60c000031240 id:25 type:2 size:65664
[W][54106.095817] pw.mem       | [           mem.c:  565 pw_mempool_alloc()] 0x608000001120: block 0x60c000031240[25] file=106/1:187831 size=65664type=2 flags=15
[D][54106.095845] pw.mem       | [           mem.c:  807 pw_mempool_find_ptr()] 0x608000001120: block:0x60c000031240 id:25 for 0x7fffdbee3000
[D][54106.095861] pw.mem       | [           mem.c:  807 pw_mempool_find_ptr()] 0x608000001120: block:0x60c000031240 id:25 for 0x7fffdbee3040
[D][54106.095873] pw.mem       | [           mem.c:  655 pw_mempool_import_block()] 0x60800000f2a0: import block:0x60c000031240 type:2 fd:106
[D][54106.095886] pw.mem       | [           mem.c:  592 mempool_find_fd()] 0x60800000f2a0: found 0x60c00000f280 id:2 fd:106 ref:1

Thread 1 "pipewire" received signal SIGILL, Illegal instruction.
mempool_find_fd (pool=0x60800000f2a0, fd=106) at ../src/pipewire/mem.c:598
598					__builtin_trap();
(gdb) bt
#0  mempool_find_fd (pool=0x60800000f2a0, fd=106) at ../src/pipewire/mem.c:598
#1  0x00007ffff6dfa4a5 in pw_mempool_import (pool=0x60800000f2a0, flags=31, type=2, fd=106) at ../src/pipewire/mem.c:613
#2  0x00007ffff6dfc047 in pw_mempool_import_block (pool=0x60800000f2a0, mem=0x60c000031240) at ../src/pipewire/mem.c:658
#3  0x00007ffff1d924cb in do_port_use_buffers (impl=0x617000002700, direction=SPA_DIRECTION_OUTPUT, port_id=1, mix_id=4294967295, flags=0, buffers=0x6110000656c0, n_buffers=2)
    at ../src/modules/module-client-node/client-node.c:823
#4  0x00007ffff1dab9c1 in impl_mix_port_use_buffers (object=0x61d000081d80, direction=SPA_DIRECTION_OUTPUT, mix_id=0, flags=0, buffers=0x6110000656c0, n_buffers=2)
    at ../src/modules/module-client-node/client-node.c:1484
#5  0x00007ffff6eb5877 in pw_impl_port_use_buffers (port=0x61d000081680, mix=0x6190000646e8, flags=0, buffers=0x6110000656c0, n_buffers=2) at ../src/pipewire/impl-port.c:1593
#6  0x00007ffff6dc1448 in do_allocation (this=0x619000064580) at ../src/pipewire/impl-link.c:540
#7  0x00007ffff6dc6990 in check_states (obj=0x619000064580, user_data=0x619000064580, res=0, id=141) at ../src/pipewire/impl-link.c:710
#8  0x00007ffff6f3864f in process_work_queue (data=0x6060000013a0, count=2) at ../src/pipewire/work-queue.c:87
#9  0x00007ffff36cd6f5 in source_event_func (source=0x6080000011a0) at ../spa/plugins/support/loop.c:615
#10 0x00007ffff36c6350 in loop_iterate (object=0x62d00000a428, timeout=-1) at ../spa/plugins/support/loop.c:452
#11 0x00007ffff6dee359 in pw_main_loop_run (loop=0x60300000b260) at ../src/pipewire/main-loop.c:148
#12 0x0000555555559723 in main (argc=0, argv=0x7ffff7021be0) at ../src/daemon/pipewire.c:131

The important moments are:

  • 54106.063392 when file descriptor 106 was imported into mempool 0x60800000f2a0 from mempool 0x608000001120
  • 54106.080949 when pw_memblock_free() closed file descriptor 106
  • 54106.095705 when file descriptor 106 was reused for a new memblock 0x60c000031240 in mempool 0x608000001120
  • 54106.095886 when do_port_use_buffers() tries to import memblock 0x60c000031240 (the one with the "reused" fd 106) but finds its own stale memblock that was imported in the first step

If things are allowed to continue, then the client process receives the wrong mem id (that of the stale memblock), maps the wrong file, and can potentially run into a SIGBUS.


I have briefly tried dup()ing the file descriptor in pw_mempool_import_block(), and while that makes the issue disappear, that looks like it's leaking file descriptors (or at least not closing them as soon as possible). And it seems like that also breaks client-node.c:node_peer_removed() (the only user of pw_mempool_find_fd()).

At first glance I see two potential ways to fix this:

  • fix the code so that the imported memblock does not outlive the source memblock, or
  • add inter-mempool reference counting to file descriptors (e.g. storing file descriptors and their reference counts separately and referencing them from memblocks, or make one memblock the "owner" of the file descriptor that is kept alive as long as the fd needs to be alive regardless of its original pool).
Edited Dec 28, 2022 by Barnabás Pőcze
Assignee
Assign to
Time tracking