Socket sharing (shiftfs enable for disk / no uid-mapping)

Olivier · September 20, 2020, 1:12pm

Hi,

First, my container uses UID/GID shifting, so here are my settings for it:

profile:

  security.idmap.isolated: true
  security.protection.shift: true

/etc/subuid and /etc/subgid:

root:100000:1000000000
root:1000:1

I do not use idmap anymore, but even if I add the following, my issue stays the same:

  raw.idmap: |-
    uid 1000 1000
    gid 1000 1000

The issue

I’m currently sharing a socket like this:

  PASocket1:
    bind: container
    connect: unix:/run/user/1000/pulse/native
    listen: unix:/home/archy/pulse-native
    security.gid: "1000"
    security.uid: "1000"
    uid: "1000"
    gid: "1000"
    mode: "0777"
    type: proxy

I get a weird behavior from it. When I connect to the socket the first time, the socket on the host receives the UID/GID 1000, but the next times I connect to it, it receives 65534.

Here is what I get:

I: [pulseaudio] client.c: Created 33 "Native client (UNIX socket client)"
I: [pulseaudio] protocol-native.c: Got credentials: uid=1000 gid=1000 success=1
I: [pulseaudio] client.c: Freed 33 "pactl"
I: [pulseaudio] protocol-native.c: Connection died.
I: [pulseaudio] client.c: Created 34 "Native client (UNIX socket client)"
I: [pulseaudio] protocol-native.c: Got credentials: uid=65534 gid=65534 success=0
W: [pulseaudio] protocol-native.c: Denied access to client with invalid authentication data.
I: [pulseaudio] client.c: Freed 34 "Native client (UNIX socket client)"
I: [pulseaudio] protocol-native.c: Connection died.
I: [pulseaudio] client.c: Created 35 "Native client (UNIX socket client)"
I: [pulseaudio] protocol-native.c: Got credentials: uid=65534 gid=65534 success=0
W: [pulseaudio] protocol-native.c: Denied access to client with invalid authentication data.
I: [pulseaudio] client.c: Freed 35 "Native client (UNIX socket client)"
I: [pulseaudio] protocol-native.c: Connection died.
I: [pulseaudio] client.c: Created 36 "Native client (UNIX socket client)"
I: [pulseaudio] protocol-native.c: Got credentials: uid=65534 gid=65534 success=0
W: [pulseaudio] protocol-native.c: Denied access to client with invalid authentication data.
I: [pulseaudio] client.c: Freed 36 "Native client (UNIX socket client)"
I: [pulseaudio] protocol-native.c: Connection died.

Is there any reason why the socket would get 1000 only the first time ? Using idmap does not seem to change anything to it, and my socket has the correct permissions on the host and guest. I tried to mount the socket as a disk with shift: true but it does not seem to work for me.

For info, the socket works perfectly the first time I use it until I disconnect, and then impossible to reconnect. The disconnect is (I guess) pretty normal as I’m running programs such as pactl or firefox.

For more info, when brute-forcing it (connecting again and again), I sometimes get the right UID/GID transmitted.

stgraber · September 20, 2020, 1:29pm

What LXD version is that?

Olivier · September 20, 2020, 1:30pm

That’s version 4.5 on Arch Linux.

toby63 · September 20, 2020, 3:31pm

@stgraber might be able to explain it better, but I think proxy devices and shiftfs have not much to do with each other.

So you don’t need root:1000:1, because that was an old method for disk devices (when you don’t have shiftfs).

I would try the following:

Update LXD to 4.6 (is available on Arch as well)
Or use lxd-git from AUR, to get the master with the newest patch for proxy devices (talked about in here).
Try the alternative method with tcp proxy device for pulseaudio, I described it here:
[Howto] Audio (via Pulseaudio) inside Container

Nonetheless your error is odd and should be investigated further, if it persists.

Can you give us the full configuration of your container?
lxc config show -e containername

Also I assume you used the latest version (1.3) of my dkms scripts for shiftfs?
(though as I said, it shouldn’t be related imo)

Olivier · September 20, 2020, 4:09pm

Thanks for the help!

I keep this one here for use with raw.idmap with some containers for the moment.

I updated to 4.6, the package just appeared in the repository. However, I still have some UID shenanigans.

Well, after more research, I found a workaround for the issue. If I delete the cookie before launching a new app needing it, it will work (i.e. rm .config/pulse/cookie && pactl info). The new cookie is the same than the old one, but the client app will then connect to the pulse server with the right UID/GID (1000).

However, I’d like to understand why the host receives something coming with an unknown UID/GID while the unix socket is UID/GID 1000 on the host and on the guest.
Knowing that if I connect with the root inside, I will have the same behavior as if I connect with user 1000 (i.e. connects as UID/GID 1000 the first time, then unknown UID/GID translated as UID/GID 65534). My hypothesis was that without the need to create the cookie, it would connect with another user (a system user maybe), but it’s working with root. So any user using the socket on the host should work I guess and the host should receive a connection from UID/GID 1000 (as long as they have the permission to access the file ofc).

In the end that’s maybe not due to LXD, but it seems the UID/GID shifting is not working as I expected somewhere.

Olivier · September 20, 2020, 4:13pm

Yes I’m using the last version of your script. I used the arch-pkg branch a few days ago.

Here you go:

architecture: x86_64
config:
  environment.DISPLAY: :0
  environment.PULSE_SERVER: unix:/home/archy/pulse-native
  image.architecture: amd64
  image.description: Archlinux current amd64 (20200920_04:40)
  image.os: Archlinux
  image.release: current
  image.serial: "20200920_04:40"
  image.type: squashfs
  security.idmap.isolated: "true"
  security.privileged: "false"
  security.protection.shift: "true"
  volatile.base_image: 7ebda547a36a071ce1da44f6cec38b934f63f6f7ed7841003d0e570d17632a7a
  volatile.eth0.host_name: veth86780519
  volatile.eth0.hwaddr: 00:16:3e:cb:99:54
  volatile.idmap.base: "165536"
  volatile.idmap.current: '[{"Isuid":true,"Isgid":false,"Hostid":165536,"Nsid":0,"Maprange":65536},{"Isuid":false,"Isgid":true,"Hostid":165536,"Nsid":0,"Maprange":65536}]'
  volatile.idmap.next: '[{"Isuid":true,"Isgid":false,"Hostid":165536,"Nsid":0,"Maprange":65536},{"Isuid":false,"Isgid":true,"Hostid":165536,"Nsid":0,"Maprange":65536}]'
  volatile.last_state.idmap: '[]'
  volatile.last_state.power: RUNNING
devices:
  PASocket1:
    bind: container
    connect: unix:/run/user/1000/pulse/native
    gid: "1000"
    listen: unix:/home/archy/pulse-native
    mode: "0777"
    security.gid: "1000"
    security.uid: "1000"
    type: proxy
    uid: "1000"
  SharedFolderCache:
    path: XXXX
    shift: "true"
    source:XXXX
    type: disk
  X0:
    bind: container
    connect: unix:@/tmp/.X11-unix/X0
    listen: unix:@/tmp/.X11-unix/X0
    security.gid: "1000"
    security.uid: "1000"
    type: proxy
  eth0:
    name: eth0
    nictype: bridged
    parent: lxdbr0
    type: nic
  mygpu:
    type: gpu
  root:
    path: /
    pool: default
    type: disk
ephemeral: false
profiles:
- firefox
stateful: false
description: ""

toby63 · September 21, 2020, 8:00pm

Ok, interesting.

So ls -l inside the container shows a correct UID/GID?
But it still connects with the wrong UID…

I recommend opening a bug report on github:
https://github.com/lxc/lxd/issues

stgraber · September 21, 2020, 8:24pm

Sorry if this was listed earlier. Your config looks correct.

Can you show ls -lh /home/archy/pulse-native in the container, ps fauxww | grep forkproxy on the host and ls -lh /run/user/1000/pulse/native on the host?

With the config above, what you should be getting is:

/home/archy/pulse-native as 1000:1000 0777 in the container (0666 would be more appropriate)
/run/user/1000/pulse/native on the host should be writable for user 1000:1000
forkproxy itself should be running as 1000:1000

stgraber · September 21, 2020, 8:24pm

The output of dmesg | grep DENIED may also be useful?

Olivier · September 21, 2020, 10:27pm

Here are the info: (the user olivier is UID/GID 1000 on the host, archy is 1000 in the container)

$ ls -lh /home/archy/pulse-native
srwxrwxrwx 1 archy archy 0 Sep 21 19:11 /home/archy/pulse-native

$ ps fauxww | grep forkproxy
olivier   199058  0.0  0.2 1271520 41460 ?       Ssl  21:11   0:00  \_ /usr/bin/lxd forkproxy -- 199020 3 unix:/home/archy/pulse-native 743 4 unix:/run/user/1000/pulse/native 1000 1000 0777 1000 1000
root      199118  0.0  0.2 1715320 44072 ?       Ssl  21:11   0:01  \_ /usr/bin/lxd forkproxy -- 199020 3 tcp:127.0.0.1:8080 743 4 tcp:127.0.0.1:8080   0644
olivier   199135  0.0  0.2 1715384 46040 ?       Ssl  21:11   0:04  \_ /usr/bin/lxd forkproxy -- 199020 3 unix:@/tmp/.X11-unix/X0 743 4 unix:@/tmp/.X11-unix/X0   0644 1000 1000
olivier   225983  0.0  0.0   3076   848 pts/5    S+   23:58   0:00      \_ grep --color forkproxy

$ ls -lh /run/user/1000/pulse/native
srw-rw-rw- 1 olivier olivier 0 Sep 20 17:44 /run/user/1000/pulse/native

There is nothing there.

I’m looking at a few more things about Pulseaudio first. I could open an issue depending on what I find.

stgraber · September 21, 2020, 10:32pm

Ok, above looks good to me so not sure why it wouldn’t work.
The proxy is running as the right user so this should all work.

You could strace -f -p 199058 and then try to connect from within the container to see if any relevant error shows up in the trace.

Olivier · September 22, 2020, 10:30am

Well, I have a weird behavior when using strace. When strace is started, the connection with pactl info is always successful, and if I stop strace, I go back to the “normal” behavior with 9/10 connections failed.

Anyway, here is the result of strace, but only with a successful connection of course:

strace: Process 4126 attached with 13 threads
[pid  5989] futex(0xc000295948, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  5988] futex(0xc00033a548, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  5987] epoll_pwait(5,  <unfinished ...>
[pid  5986] futex(0xc000295148, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  5801] futex(0xc00033a148, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  5745] epoll_wait(9,  <unfinished ...>
[pid  4140] futex(0x5613cbb73f60, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  4135] futex(0x5613cbb73dd8, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  4133] futex(0xc000100148, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  4132] futex(0xc00005ad48, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  4129] futex(0xc00005a948, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  4128] restart_syscall(<... resuming interrupted read ...> <unfinished ...>
[pid  4126] futex(0x5613cb6188a8, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  5987] <... epoll_pwait resumed>[{EPOLLIN, {u32=3775105080, u64=140204392548408}}], 128, -1, NULL, 0) = 1
[pid  5745] <... epoll_wait resumed>[{EPOLLIN, {u32=4, u64=4}}], 10, -1) = 1
[pid  5987] epoll_pwait(5,  <unfinished ...>
[pid  5745] futex(0x5613cb617c18, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  5987] <... epoll_pwait resumed>[], 128, 0, NULL, 114) = 0
[pid  5745] <... futex resumed>)        = 1
[pid  5987] sched_yield( <unfinished ...>
[pid  4128] <... restart_syscall resumed>) = 0
[pid  5987] <... sched_yield resumed>)  = 0
[pid  5745] accept4(8,  <unfinished ...>
[pid  5987] futex(0x5613cb617b18, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5745] <... accept4 resumed>{sa_family=AF_UNIX}, [112->2], SOCK_CLOEXEC|SOCK_NONBLOCK) = 10
[pid  5987] <... futex resumed>)        = 0
[pid  5987] epoll_pwait(5,  <unfinished ...>
[pid  5745] epoll_ctl(5, EPOLL_CTL_ADD, 10, {EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, {u32=3775104856, u64=140204392548184}} <unfinished ...>
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5745] <... epoll_ctl resumed>)    = 0
[pid  5987] <... epoll_pwait resumed>[{EPOLLIN|EPOLLOUT, {u32=3775104856, u64=140204392548184}}], 128, -1, NULL, 0) = 1
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5987] epoll_pwait(5,  <unfinished ...>
[pid  5745] getsockname(10,  <unfinished ...>
[pid  5987] <... epoll_pwait resumed>[], 128, 0, NULL, 233) = 0
[pid  5745] <... getsockname resumed>{sa_family=AF_UNIX, sun_path="/home/archy/pulse-native"}, [112->27]) = 0
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5987] epoll_pwait(5,  <unfinished ...>
[pid  5745] socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0 <unfinished ...>
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5745] <... socket resumed>)       = 11
[pid  5745] connect(11, {sa_family=AF_UNIX, sun_path="/run/user/1000/pulse/native"}, 30 <unfinished ...>
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5745] <... connect resumed>)      = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5745] epoll_ctl(5, EPOLL_CTL_ADD, 11, {EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, {u32=3775104632, u64=140204392547960}} <unfinished ...>
[pid  5987] <... epoll_pwait resumed>[{EPOLLOUT, {u32=3775104632, u64=140204392547960}}], 128, -1, NULL, 0) = 1
[pid  5745] <... epoll_ctl resumed>)    = 0
[pid  5987] epoll_pwait(5,  <unfinished ...>
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5987] <... epoll_pwait resumed>[], 128, 0, NULL, 119) = 0
[pid  5745] getsockname(11,  <unfinished ...>
[pid  5987] epoll_pwait(5,  <unfinished ...>
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5745] <... getsockname resumed>{sa_family=AF_UNIX}, [112->2]) = 0
[pid  5745] getpeername(11,  <unfinished ...>
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5745] <... getpeername resumed>{sa_family=AF_UNIX, sun_path="/run/user/1000/pulse/native"}, [112->30]) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5745] futex(0xc00033a148, FUTEX_WAKE_PRIVATE, 1) = 1
[pid  5801] <... futex resumed>)        = 0
[pid  5745] epoll_wait(9,  <unfinished ...>
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5801] futex(0xc000295148, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5986] <... futex resumed>)        = 0
[pid  5801] <... futex resumed>)        = 1
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5986] futex(0xc000295148, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  5801] futex(0xc000295148, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5986] <... futex resumed>)        = -1 EAGAIN (Resource temporarily unavailable)
[pid  5801] <... futex resumed>)        = 0
[pid  5986] nanosleep({tv_sec=0, tv_nsec=3000},  <unfinished ...>
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5801] recvmsg(11,  <unfinished ...>
[pid  5986] <... nanosleep resumed>NULL) = 0
[pid  5801] <... recvmsg resumed>{msg_namelen=112}, 0) = -1 EAGAIN (Resource temporarily unavailable)
[pid  5986] futex(0xc00005a948, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5986] <... futex resumed>)        = 1
[pid  5801] futex(0xc00033a148, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  4129] <... futex resumed>)        = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5986] recvmsg(10,  <unfinished ...>
[pid  4129] futex(0xc00005a948, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  5986] <... recvmsg resumed>{msg_name=0xc0002d4ae8, msg_namelen=112->0, msg_iov=[{iov_base="\0\0\1\24\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0L\0\0\0\10L\0\0\0\0L@"..., iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 296
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5986] sendmsg(11, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\0\1\24\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0L\0\0\0\10L\0\0\0\0L@"..., iov_len=296}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0 <unfinished ...>
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5986] <... sendmsg resumed>)      = 296
[pid  5986] recvmsg(10, {msg_namelen=112}, 0) = -1 EAGAIN (Resource temporarily unavailable)
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5987] <... epoll_pwait resumed>[{EPOLLOUT, {u32=3775104632, u64=140204392547960}}], 128, -1, NULL, 0) = 1
[pid  5986] futex(0xc000295148, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  5987] epoll_pwait(5,  <unfinished ...>
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5987] <... epoll_pwait resumed>[{EPOLLIN|EPOLLOUT, {u32=3775104632, u64=140204392547960}}], 128, 0, NULL, 119) = 1
[pid  5987] futex(0xc000295148, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5987] <... futex resumed>)        = 1
[pid  5986] <... futex resumed>)        = 0
[pid  5987] recvmsg(11,  <unfinished ...>
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5987] <... recvmsg resumed>{msg_name={sa_family=AF_UNIX, sun_path="/run/user/1000/pulse/native"}, msg_namelen=112->30, msg_iov=[{iov_base="\0\0\0\17\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0L\0\0\0\2L\0\0\0\0L\0"..., iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 35
[pid  5986] epoll_pwait(5,  <unfinished ...>
[pid  5987] sendmsg(10, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\0\0\17\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0L\0\0\0\2L\0\0\0\0L\0"..., iov_len=35}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0 <unfinished ...>
[pid  5986] <... epoll_pwait resumed>[], 128, 0, NULL, 0) = 0
[pid  5987] <... sendmsg resumed>)      = 35
[pid  5986] epoll_pwait(5,  <unfinished ...>
[pid  5987] recvmsg(11,  <unfinished ...>
[pid  5986] <... epoll_pwait resumed>[{EPOLLOUT, {u32=3775104856, u64=140204392548184}}], 128, -1, NULL, 0) = 1
[pid  5987] <... recvmsg resumed>{msg_namelen=112}, 0) = -1 EAGAIN (Resource temporarily unavailable)
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5987] epoll_pwait(5,  <unfinished ...>
[pid  5986] epoll_pwait(5,  <unfinished ...>
[pid  5987] <... epoll_pwait resumed>[], 128, 0, NULL, 94643007415392) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5987] epoll_pwait(5,  <unfinished ...>
[pid  5986] <... epoll_pwait resumed>[], 128, 0, NULL, 119) = 0
[pid  5986] futex(0xc000295148, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  5987] <... epoll_pwait resumed>[{EPOLLIN|EPOLLOUT, {u32=3775104856, u64=140204392548184}}], 128, -1, NULL, 0) = 1
[pid  5987] recvmsg(10, {msg_name=0xc0002d4ae8, msg_namelen=112->0, msg_iov=[{iov_base="\0\0\1e\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0L\0\0\0\tL\0\0\0\1Pt"..., iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 377
[pid  5987] sendmsg(11, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\0\1e\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0L\0\0\0\tL\0\0\0\1Pt"..., iov_len=377}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0 <unfinished ...>
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5987] <... sendmsg resumed>)      = 377
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5987] recvmsg(10, {msg_namelen=112}, 0) = -1 EAGAIN (Resource temporarily unavailable)
[pid  5987] epoll_pwait(5, [{EPOLLOUT, {u32=3775104856, u64=140204392548184}}, {EPOLLOUT, {u32=3775104632, u64=140204392547960}}], 128, 0, NULL, 94643007415392) = 2
[pid  5987] epoll_pwait(5, [{EPOLLIN|EPOLLOUT, {u32=3775104632, u64=140204392547960}}], 128, -1, NULL, 0) = 1
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5987] recvmsg(11,  <unfinished ...>
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5987] <... recvmsg resumed>{msg_name={sa_family=AF_UNIX, sun_path="/run/user/1000/pulse/native"}, msg_namelen=112->30, msg_iov=[{iov_base="\0\0\0\17\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0L\0\0\0\2L\0\0\0\1L\0"..., iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 35
[pid  5987] sendmsg(10, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\0\0\17\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0L\0\0\0\2L\0\0\0\1L\0"..., iov_len=35}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 35
[pid  5987] recvmsg(11, {msg_namelen=112}, 0) = -1 EAGAIN (Resource temporarily unavailable)
[pid  5987] epoll_pwait(5,  <unfinished ...>
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5987] <... epoll_pwait resumed>[{EPOLLIN|EPOLLOUT, {u32=3775104856, u64=140204392548184}}], 128, 0, NULL, 94643007415392) = 1
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5987] recvmsg(10, {msg_name=0xc0002d4ae8, msg_namelen=112->0, msg_iov=[{iov_base="\0\0\0\n\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0L\0\0\0\24L\0\0\0\2", iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 30
[pid  5987] sendmsg(11, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\0\0\n\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0L\0\0\0\24L\0\0\0\2", iov_len=30}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 30
[pid  5987] recvmsg(10, {msg_namelen=112}, 0) = -1 EAGAIN (Resource temporarily unavailable)
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5987] epoll_pwait(5,  <unfinished ...>
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5987] <... epoll_pwait resumed>[{EPOLLIN|EPOLLOUT, {u32=3775104632, u64=140204392547960}}], 128, 0, NULL, 94643007415392) = 1
[pid  5987] recvmsg(11, {msg_name={sa_family=AF_UNIX, sun_path="/run/user/1000/pulse/native"}, msg_namelen=112->30, msg_iov=[{iov_base="\0\0\0\220\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0L\0\0\0\2L\0\0\0\2tp"..., iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 164
[pid  5987] sendmsg(10, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\0\0\220\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0L\0\0\0\2L\0\0\0\2tp"..., iov_len=164}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 164
[pid  5987] recvmsg(11,  <unfinished ...>
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5987] <... recvmsg resumed>{msg_namelen=112}, 0) = -1 EAGAIN (Resource temporarily unavailable)
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5987] epoll_pwait(5, [{EPOLLOUT, {u32=3775104856, u64=140204392548184}}], 128, 0, NULL, 94643007415392) = 1
[pid  5987] epoll_pwait(5, [{EPOLLIN|EPOLLOUT|EPOLLHUP|EPOLLRDHUP, {u32=3775104856, u64=140204392548184}}], 128, -1, NULL, 0) = 1
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5987] recvmsg(10,  <unfinished ...>
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5987] <... recvmsg resumed>{msg_name=0xc0002d4ae8, msg_namelen=112->0, msg_iov=[{iov_base="", iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 0
[pid  5987] futex(0xc000295148, FUTEX_WAKE_PRIVATE, 1) = 1
[pid  5986] <... futex resumed>)        = 0
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5986] epoll_pwait(5,  <unfinished ...>
[pid  5987] epoll_ctl(5, EPOLL_CTL_DEL, 11, 0xc0005dcb34 <unfinished ...>
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5987] <... epoll_ctl resumed>)    = 0
[pid  5986] <... epoll_pwait resumed>[], 128, 0, NULL, 0) = 0
[pid  5987] close(11 <unfinished ...>
[pid  5986] epoll_pwait(5,  <unfinished ...>
[pid  5987] <... close resumed>)        = 0
[pid  5987] futex(0xc00005a948, FUTEX_WAKE_PRIVATE, 1) = 1
[pid  4129] <... futex resumed>)        = 0
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  5987] epoll_ctl(5, EPOLL_CTL_DEL, 10, 0xc0005ed59c <unfinished ...>
[pid  4129] futex(0xc00005a948, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  5987] <... epoll_ctl resumed>)    = 0
[pid  5987] close(10)                   = 0
[pid  5987] futex(0xc000295548, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  4128] <... nanosleep resumed>NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=40000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=80000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=160000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=320000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=640000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=1280000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=2560000}, NULL) = 0
[pid  4128] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  4128] futex(0x5613cb617c18, FUTEX_WAIT_PRIVATE, 0, {tv_sec=60, tv_nsec=0}^Cstrace: Process 4126 detached
strace: Process 4128 detached
 <detached ...>
strace: Process 4129 detached
strace: Process 4132 detached
strace: Process 4133 detached
strace: Process 4135 detached
strace: Process 4140 detached
strace: Process 5745 detached
strace: Process 5801 detached
strace: Process 5986 detached
strace: Process 5987 detached
strace: Process 5988 detached
strace: Process 5989 detached

stgraber · September 22, 2020, 1:41pm

Hmm, that’s very odd and would suggest some kind of race condition as strace will slow down the traced process usually.

This is pretty confusing stuff. I wonder if stracing pulseaudio may be more useful to see if it’s indeed receiving the wrong ucred somehow.

Olivier · September 23, 2020, 2:40pm

I traced pulseaudio instead and the result is the same. If strace is active, the connection works, and if it’s not, it’s gonna mostly fail.

Here is the trace anyway:

$ ps fauxww | grep pulseaudio
olivier   244730  0.1  0.0 494232 12700 ?        S<sl 16:31   0:00  \_ /usr/bin/pulseaudio --daemonize=no
olivier   258283  0.0  0.0   3076   796 pts/1    S+   16:36   0:00      \_ grep --color pulseaudio

$ sudo strace -f -p 244730
strace: Process 244730 attached with 3 threads
[pid 244748] ppoll([{fd=25, events=POLLIN}, {fd=28, events=POLLIN|POLLERR|POLLNVAL}, {fd=26, events=POLLIN}], 3, NULL, NULL, 8 <unfinished ...>
[pid 244747] ppoll([{fd=18, events=POLLIN}, {fd=23, events=POLLIN|POLLERR|POLLNVAL}, {fd=19, events=POLLIN}], 3, NULL, NULL, 8 <unfinished ...>
[pid 244730] ppoll([{fd=4, events=POLLIN}, {fd=9, events=POLLIN}, {fd=22, events=POLLIN}, {fd=16, events=POLLIN}, {fd=33, events=POLLIN}, {fd=32, events=POLLIN}, {fd=3, events=POLLIN}, {fd=31, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=0}, {fd=24, events=POLLIN}, {fd=27, events=POLLIN}, {fd=17, events=POLLIN}, {fd=20, events=POLLIN}, {fd=15, events=POLLIN|POLLERR|POLLHUP}, {fd=15, events=0}, {fd=14, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7, events=POLLIN}], 19, NULL, NULL, 8) = 1 ([{fd=3, revents=POLLIN}])
[pid 244730] accept4(3, NULL, NULL, SOCK_CLOEXEC) = 21
[pid 244730] fcntl(21, F_GETFD)         = 0x1 (flags FD_CLOEXEC)
[pid 244730] setsockopt(21, SOL_SOCKET, SO_PRIORITY, [6], 4) = 0
[pid 244730] fcntl(21, F_GETFL)         = 0x2 (flags O_RDWR)
[pid 244730] fcntl(21, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] fstat(21, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0
[pid 244730] getpeername(21, {sa_family=AF_UNIX}, [128->2]) = 0
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] getpeername(21, {sa_family=AF_UNIX}, [128->2]) = 0
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] setsockopt(21, SOL_SOCKET, SO_RCVBUF, [65472], 4) = 0
[pid 244730] setsockopt(21, SOL_SOCKET, SO_SNDBUF, [65472], 4) = 0
[pid 244730] getsockname(21, {sa_family=AF_UNIX, sun_path="/run/user/1000/pulse/native"}, [256->30]) = 0
[pid 244730] setsockopt(21, SOL_SOCKET, SO_PASSCRED, [1], 4) = 0
[pid 244730] read(4, "WWWW", 10)        = 4
[pid 244730] read(4, 0x7ffc391cc05e, 10) = -1 EAGAIN (Resource temporarily unavailable)
[pid 244730] ppoll([{fd=4, events=POLLIN}, {fd=21, events=POLLIN|POLLOUT}, {fd=9, events=POLLIN}, {fd=22, events=POLLIN}, {fd=16, events=POLLIN}, {fd=33, events=POLLIN}, {fd=32, events=POLLIN}, {fd=3, events=POLLIN}, {fd=31, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=0}, {fd=24, events=POLLIN}, {fd=27, events=POLLIN}, {fd=17, events=POLLIN}, {fd=20, events=POLLIN}, {fd=15, events=POLLIN|POLLERR|POLLHUP}, {fd=15, events=0}, {fd=14, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7, events=POLLIN}], 20, {tv_sec=59, tv_nsec=999819000}, NULL, 8) = 1 ([{fd=21, revents=POLLIN|POLLOUT}], left {tv_sec=59, tv_nsec=999813955})
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] recvmsg(21, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\0\1\24\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0", iov_len=20}], msg_iovlen=1, msg_control=[{cmsg_len=28, cmsg_level=SOL_SOCKET, cmsg_type=SCM_CREDENTIALS, cmsg_data={pid=246871, uid=1000, gid=1000}}], msg_controllen=32, msg_flags=0}, 0) = 20
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] read(4, "WW", 10)          = 2
[pid 244730] ppoll([{fd=4, events=POLLIN}, {fd=21, events=POLLIN}, {fd=9, events=POLLIN}, {fd=22, events=POLLIN}, {fd=16, events=POLLIN}, {fd=33, events=POLLIN}, {fd=32, events=POLLIN}, {fd=3, events=POLLIN}, {fd=31, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=0}, {fd=24, events=POLLIN}, {fd=27, events=POLLIN}, {fd=17, events=POLLIN}, {fd=20, events=POLLIN}, {fd=15, events=POLLIN|POLLERR|POLLHUP}, {fd=15, events=0}, {fd=14, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7, events=POLLIN}], 20, {tv_sec=59, tv_nsec=999671000}, NULL, 8) = 1 ([{fd=21, revents=POLLIN}], left {tv_sec=59, tv_nsec=999668750})
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] recvmsg(21, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="L\0\0\0\10L\0\0\0\0L@\0\0!x\0\0\1\0\332j6\216$\230\341*\222\21f\250"..., iov_len=276}], msg_iovlen=1, msg_control=[{cmsg_len=28, cmsg_level=SOL_SOCKET, cmsg_type=SCM_CREDENTIALS, cmsg_data={pid=246871, uid=1000, gid=1000}}], msg_controllen=32, msg_flags=0}, 0) = 276
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] getuid()                   = 1000
[pid 244730] getuid()                   = 1000
[pid 244730] getgid()                   = 1000
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] getpid()                   = 244730
[pid 244730] sendmsg(21, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\0\0\17\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0L\0\0\0\2L\0\0\0\0L\0"..., iov_len=35}], msg_iovlen=1, msg_control=[{cmsg_len=28, cmsg_level=SOL_SOCKET, cmsg_type=SCM_CREDENTIALS, cmsg_data={pid=244730, uid=1000, gid=1000}}], msg_controllen=32, msg_flags=0}, MSG_NOSIGNAL) = 35
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] read(4, "WWWW", 10)        = 4
[pid 244730] read(4, 0x7ffc391cc05e, 10) = -1 EAGAIN (Resource temporarily unavailable)
[pid 244730] ppoll([{fd=4, events=POLLIN}, {fd=21, events=POLLIN|POLLOUT}, {fd=9, events=POLLIN}, {fd=22, events=POLLIN}, {fd=16, events=POLLIN}, {fd=33, events=POLLIN}, {fd=32, events=POLLIN}, {fd=3, events=POLLIN}, {fd=31, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=0}, {fd=24, events=POLLIN}, {fd=27, events=POLLIN}, {fd=17, events=POLLIN}, {fd=20, events=POLLIN}, {fd=15, events=POLLIN|POLLERR|POLLHUP}, {fd=15, events=0}, {fd=14, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7, events=POLLIN}], 20, NULL, NULL, 8) = 1 ([{fd=21, revents=POLLOUT}])
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] read(4, "W", 10)           = 1
[pid 244730] ppoll([{fd=4, events=POLLIN}, {fd=21, events=POLLIN}, {fd=9, events=POLLIN}, {fd=22, events=POLLIN}, {fd=16, events=POLLIN}, {fd=33, events=POLLIN}, {fd=32, events=POLLIN}, {fd=3, events=POLLIN}, {fd=31, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=0}, {fd=24, events=POLLIN}, {fd=27, events=POLLIN}, {fd=17, events=POLLIN}, {fd=20, events=POLLIN}, {fd=15, events=POLLIN|POLLERR|POLLHUP}, {fd=15, events=0}, {fd=14, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7, events=POLLIN}], 20, NULL, NULL, 8) = 1 ([{fd=21, revents=POLLIN}])
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] recvmsg(21, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\0\1e\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0", iov_len=20}], msg_iovlen=1, msg_control=[{cmsg_len=28, cmsg_level=SOL_SOCKET, cmsg_type=SCM_CREDENTIALS, cmsg_data={pid=246871, uid=1000, gid=1000}}], msg_controllen=32, msg_flags=0}, 0) = 20
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] read(4, "WW", 10)          = 2
[pid 244730] ppoll([{fd=4, events=POLLIN}, {fd=21, events=POLLIN}, {fd=9, events=POLLIN}, {fd=22, events=POLLIN}, {fd=16, events=POLLIN}, {fd=33, events=POLLIN}, {fd=32, events=POLLIN}, {fd=3, events=POLLIN}, {fd=31, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=0}, {fd=24, events=POLLIN}, {fd=27, events=POLLIN}, {fd=17, events=POLLIN}, {fd=20, events=POLLIN}, {fd=15, events=POLLIN|POLLERR|POLLHUP}, {fd=15, events=0}, {fd=14, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7, events=POLLIN}], 20, NULL, NULL, 8) = 1 ([{fd=21, revents=POLLIN}])
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] recvmsg(21, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="L\0\0\0\tL\0\0\0\1Ptapplication.process."..., iov_len=357}], msg_iovlen=1, msg_control=[{cmsg_len=28, cmsg_level=SOL_SOCKET, cmsg_type=SCM_CREDENTIALS, cmsg_data={pid=246871, uid=1000, gid=1000}}], msg_controllen=32, msg_flags=0}, 0) = 357
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] sendto(21, "\0\0\0\17\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0L\0\0\0\2L\0\0\0\1L\0"..., 35, MSG_NOSIGNAL, NULL, 0) = 35
[pid 244730] read(4, "WWWW", 10)        = 4
[pid 244730] read(4, 0x7ffc391cc05e, 10) = -1 EAGAIN (Resource temporarily unavailable)
[pid 244730] ppoll([{fd=4, events=POLLIN}, {fd=21, events=POLLIN}, {fd=9, events=POLLIN}, {fd=22, events=POLLIN}, {fd=16, events=POLLIN}, {fd=33, events=POLLIN}, {fd=32, events=POLLIN}, {fd=3, events=POLLIN}, {fd=31, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=0}, {fd=24, events=POLLIN}, {fd=27, events=POLLIN}, {fd=17, events=POLLIN}, {fd=20, events=POLLIN}, {fd=15, events=POLLIN|POLLERR|POLLHUP}, {fd=15, events=0}, {fd=14, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7, events=POLLIN}], 20, NULL, NULL, 8) = 1 ([{fd=21, revents=POLLIN}])
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] recvmsg(21, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\0\0\n\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0", iov_len=20}], msg_iovlen=1, msg_control=[{cmsg_len=28, cmsg_level=SOL_SOCKET, cmsg_type=SCM_CREDENTIALS, cmsg_data={pid=246871, uid=1000, gid=1000}}], msg_controllen=32, msg_flags=0}, 0) = 20
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] read(4, "WW", 10)          = 2
[pid 244730] ppoll([{fd=4, events=POLLIN}, {fd=21, events=POLLIN}, {fd=9, events=POLLIN}, {fd=22, events=POLLIN}, {fd=16, events=POLLIN}, {fd=33, events=POLLIN}, {fd=32, events=POLLIN}, {fd=3, events=POLLIN}, {fd=31, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=0}, {fd=24, events=POLLIN}, {fd=27, events=POLLIN}, {fd=17, events=POLLIN}, {fd=20, events=POLLIN}, {fd=15, events=POLLIN|POLLERR|POLLHUP}, {fd=15, events=0}, {fd=14, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7, events=POLLIN}], 20, NULL, NULL, 8) = 1 ([{fd=21, revents=POLLIN}])
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] recvmsg(21, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="L\0\0\0\24L\0\0\0\2", iov_len=10}], msg_iovlen=1, msg_control=[{cmsg_len=28, cmsg_level=SOL_SOCKET, cmsg_type=SCM_CREDENTIALS, cmsg_data={pid=246871, uid=1000, gid=1000}}], msg_controllen=32, msg_flags=0}, 0) = 10
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] getuid()                   = 1000
[pid 244730] uname({sysname="Linux", nodename="portol", ...}) = 0
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] sendto(21, "\0\0\0\224\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0L\0\0\0\2L\0\0\0\2tp"..., 168, MSG_NOSIGNAL, NULL, 0) = 168
[pid 244730] read(4, "WWW", 10)         = 3
[pid 244730] read(4, 0x7ffc391cc05e, 10) = -1 EAGAIN (Resource temporarily unavailable)
[pid 244730] ppoll([{fd=4, events=POLLIN}, {fd=21, events=POLLIN}, {fd=9, events=POLLIN}, {fd=22, events=POLLIN}, {fd=16, events=POLLIN}, {fd=33, events=POLLIN}, {fd=32, events=POLLIN}, {fd=3, events=POLLIN}, {fd=31, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=0}, {fd=24, events=POLLIN}, {fd=27, events=POLLIN}, {fd=17, events=POLLIN}, {fd=20, events=POLLIN}, {fd=15, events=POLLIN|POLLERR|POLLHUP}, {fd=15, events=0}, {fd=14, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7, events=POLLIN}], 20, NULL, NULL, 8) = 1 ([{fd=21, revents=POLLIN|POLLHUP}])
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] recvmsg(21, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="", iov_len=20}], msg_iovlen=1, msg_control=[{cmsg_len=28, cmsg_level=SOL_SOCKET, cmsg_type=SCM_CREDENTIALS, cmsg_data={pid=0, uid=0, gid=0}}], msg_controllen=32, msg_flags=0}, 0) = 0
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] close(21)                  = 0
[pid 244730] write(5, "W", 1)           = 1
[pid 244730] read(4, "WWWW", 10)        = 4
[pid 244730] read(4, 0x7ffc391cc05e, 10) = -1 EAGAIN (Resource temporarily unavailable)
[pid 244730] ppoll([{fd=4, events=POLLIN}, {fd=9, events=POLLIN}, {fd=22, events=POLLIN}, {fd=16, events=POLLIN}, {fd=33, events=POLLIN}, {fd=32, events=POLLIN}, {fd=3, events=POLLIN}, {fd=31, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=POLLIN|POLLERR|POLLHUP}, {fd=30, events=0}, {fd=24, events=POLLIN}, {fd=27, events=POLLIN}, {fd=17, events=POLLIN}, {fd=20, events=POLLIN}, {fd=15, events=POLLIN|POLLERR|POLLHUP}, {fd=15, events=0}, {fd=14, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7, events=POLLIN}], 19, NULL, NULL, 8^Cstrace: Process 244730 detached
 <detached ...>
strace: Process 244747 detached
strace: Process 244748 detached

I would be happy to do more tests if you have some ideas. On my side, I’m gonna make it work by sharing the authentication cookie between the host and guest or accepting anonymous connections on pulseaudio.