This is related with systemd and dbus. Possibly nsswitch, ldap and nscd. However dbus sees the user as not being authenticated. As such, I'm switching this over to dbus.
We see this issue every now and then depending on what we install so I feel there's a race condition taking place which affects the order. I'll put more details below, hopefully we can at least advise others on this particular scenario if it's not a bug, however as systemd has before, after methods, perhaps we can refine the unit files? ** Package changed: systemd (Ubuntu) => dbus (Ubuntu) -- You received this bug notification because you are a member of Ubuntu Touch seeded packages, which is subscribed to dbus in Ubuntu. https://bugs.launchpad.net/bugs/1885948 Title: systemd 229 (16.04) and 237 (18.04) error with "Failed to get properties: Access denied" when ran as non-root user Status in dbus package in Ubuntu: New Bug description: I've seen this bug reported but almost always it is when being ran as root. This however is only an issue when ran as a non-root user. The root user is fine. I've come across this several times and although it's not a major issue, the only solution I've found is to reboot the system. I see this when running strace, tracing the network. We recently installed docker-ce and updated our version of salt from 2016.8.3 using python 2 to 2019.2.4 using python 3. ### 16.04 - systemd 229 on d1lmonitoringdev1 ### ## non-root user ## $ strace -f -s 16384 -e trace=network systemctl status ntp socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3 getsockopt(3, SOL_SOCKET, SO_RCVBUF, [212992], [4]) = 0 setsockopt(3, SOL_SOCKET, SO_RCVBUFFORCE, [8388608], 4) = -1 EPERM (Operation not permitted) setsockopt(3, SOL_SOCKET, SO_RCVBUF, [8388608], 4) = 0 getsockopt(3, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0 setsockopt(3, SOL_SOCKET, SO_SNDBUFFORCE, [8388608], 4) = -1 EPERM (Operation not permitted) setsockopt(3, SOL_SOCKET, SO_SNDBUF, [8388608], 4) = 0 connect(3, {sa_family=AF_LOCAL, sun_path="/var/run/dbus/system_bus_socket"}, 33) = 0 getsockopt(3, SOL_SOCKET, SO_PEERCRED, {pid=1, uid=0, gid=0}, [12]) = 0 getsockopt(3, SOL_SOCKET, SO_ACCEPTCONN, [0], [4]) = 0 getsockname(3, {sa_family=AF_LOCAL, NULL}, [2]) = 0 sendmsg(3, {msg_name(0)=NULL, msg_iov(3)=[{"\0AUTH EXTERNAL ", 15}, {"3130313631", 10}, {"\r\nNEGOTIATE_UNIX_FD\r\nBEGIN\r\n", 28}], msg_controllen=0, msg_flags=0}, MSG_DONTWAIT|MSG_NOSIGNAL) = 53 recvmsg(3, {msg_name(0)=NULL, msg_iov(1)=[{"REJECTED EXTERNAL DBUS_COOKIE_SHA1 ANONYMOUS\r\nERROR \"Need to authenticate first\"\r\n", 256}], msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_NOSIGNAL|MSG_CMSG_CLOEXEC) = 82 strace: Process 29413 attached [pid 29413] --- SIGCONT {si_signo=SIGCONT, si_code=SI_USER, si_pid=29412, si_uid=10161} --- Failed to get properties: Access denied [pid 29413] +++ exited with 0 +++ --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=29413, si_uid=10161, si_status=0, si_utime=0, si_stime=0} --- +++ exited with 1 +++ ## root user ## # Truncated because as root it works. $ sudo strace -f -s 16384 -e trace=network systemctl status ntp [sudo] password for zbukhari: socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3 getsockopt(3, SOL_SOCKET, SO_RCVBUF, [212992], [4]) = 0 setsockopt(3, SOL_SOCKET, SO_RCVBUFFORCE, [8388608], 4) = 0 getsockopt(3, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0 setsockopt(3, SOL_SOCKET, SO_SNDBUFFORCE, [8388608], 4) = 0 connect(3, {sa_family=AF_LOCAL, sun_path="/run/systemd/private"}, 22) = 0 getsockopt(3, SOL_SOCKET, SO_PEERCRED, {pid=1, uid=0, gid=0}, [12]) = 0 getsockopt(3, SOL_SOCKET, SO_ACCEPTCONN, [0], [4]) = 0 getsockname(3, {sa_family=AF_LOCAL, NULL}, [2]) = 0 sendmsg(3, {msg_name(0)=NULL, msg_iov(3)=[{"\0AUTH EXTERNAL ", 15}, {"30", 2}, {"\r\nNEGOTIATE_UNIX_FD\r\nBEGIN\r\n", 28}], msg_controllen=0, msg_flags=0}, MSG_DONTWAIT|MSG_NOSIGNAL) = 45 getsockopt(3, SOL_SOCKET, SO_PEERCRED, {pid=1, uid=0, gid=0}, [12]) = 0 recvmsg(3, {msg_name(0)=NULL, msg_iov(1)=[{"OK 3139491ef18e4f4c84fae863d4dd042f\r\nAGREE_UNIX_FD\r\n", 256}], msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_NOSIGNAL|MSG_CMSG_CLOEXEC) = 52 sendmsg(3, {msg_name(0)=NULL, msg_iov(2)=[{"l\1\4\1\5\0\0\0\1\0\0\0\237\0\0\0\1\1o\0,\0\0\0/org/freedesktop/systemd1/unit/ntp_2eservice\0\0\0\0\3\1s\0\6\0\0\ 0GetAll\0\0\2\1s\0\37\0\0\0org.freedesktop.DBus.Properties\0\6\1s\0\30\0\0\0org.freedesktop.systemd1\0\0\0\0\0\0\0\0\10\1g\0\1s\0\0", 176}, {"\0\0\0\0\0", 5}], msg_controllen=0, msg_flags=0}, MSG_DONTWAIT|MSG_NOSIGNAL) = 181 recvmsg(3, {msg_name(0)=NULL, msg_iov(1)=[{"l\2\1\1\35 \0\0\1\0\0\0\23\0\0\0\5\1u\0\1\0\0\0", 24}], msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_NOSIGNAL|MSG_CMSG_CLOEXEC) = 24 ### 18.04 - systemd 237 on d1lzbbyodev1 ### ## non-root user ## $ strace -f -s 16384 -e trace=%network systemctl status ntp socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3 getsockopt(3, SOL_SOCKET, SO_RCVBUF, [212992], [4]) = 0 setsockopt(3, SOL_SOCKET, SO_RCVBUFFORCE, [8388608], 4) = -1 EPERM (Operation not permitted) setsockopt(3, SOL_SOCKET, SO_RCVBUF, [8388608], 4) = 0 getsockopt(3, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0 setsockopt(3, SOL_SOCKET, SO_SNDBUFFORCE, [8388608], 4) = -1 EPERM (Operation not permitted) setsockopt(3, SOL_SOCKET, SO_SNDBUF, [8388608], 4) = 0 connect(3, {sa_family=AF_UNIX, sun_path="/run/dbus/system_bus_socket"}, 29) = 0 getsockopt(3, SOL_SOCKET, SO_PEERCRED, {pid=1, uid=0, gid=0}, [12]) = 0 getsockopt(3, SOL_SOCKET, SO_PEERSEC, 0x56338b39b450, [64]) = -1 ENOPROTOOPT (Protocol not available) getsockopt(3, SOL_SOCKET, SO_PEERGROUPS, "", [256->0]) = 0 getsockopt(3, SOL_SOCKET, SO_ACCEPTCONN, [0], [4]) = 0 getsockname(3, {sa_family=AF_UNIX}, [128->2]) = 0 sendmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0AUTH EXTERNAL ", iov_len=15}, {iov_base="3130313631", iov_len=10}, {iov_base="\r\nNEGOTIATE_UNIX_FD\r\nBEGIN\r\n", iov_len=28}], msg_iovlen=3, msg_controllen=0, msg_flags=0}, MSG_DONTWAIT|MSG_NOSIGNAL) = 53 strace: Process 22703 attached [pid 22702] recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="REJECTED EXTERNAL\r\nERROR \"Need to authenticate first\"\r\n", iov_len=256}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_NOSIGNAL|MSG_CMSG_CLOEXEC) = 55 [pid 22703] --- SIGCONT {si_signo=SIGCONT, si_code=SI_USER, si_pid=22702, si_uid=10161} --- Failed to get properties: Access denied [pid 22703] +++ exited with 0 +++ --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=22703, si_uid=10161, si_status=0, si_utime=0, si_stime=0} --- +++ exited with 1 +++ ## root user ## # truncated because as root it works. $ sudo strace -f -s 16384 -e trace=%network systemctl status ntp socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3 getsockopt(3, SOL_SOCKET, SO_RCVBUF, [212992], [4]) = 0 setsockopt(3, SOL_SOCKET, SO_RCVBUFFORCE, [8388608], 4) = 0 getsockopt(3, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0 setsockopt(3, SOL_SOCKET, SO_SNDBUFFORCE, [8388608], 4) = 0 connect(3, {sa_family=AF_UNIX, sun_path="/run/systemd/private"}, 22) = 0 getsockopt(3, SOL_SOCKET, SO_PEERCRED, {pid=1, uid=0, gid=0}, [12]) = 0 getsockopt(3, SOL_SOCKET, SO_PEERSEC, 0x557f1d186450, [64]) = -1 ENOPROTOOPT (Protocol not available) getsockopt(3, SOL_SOCKET, SO_PEERGROUPS, "", [256->0]) = 0 getsockopt(3, SOL_SOCKET, SO_ACCEPTCONN, [0], [4]) = 0 getsockname(3, {sa_family=AF_UNIX}, [128->2]) = 0 sendmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0AUTH EXTERNAL ", iov_len=15}, {iov_base="30", iov_len=2}, {iov_base="\r\nNEGOTIATE_UNIX_FD\r\nBEGIN\r\n", iov_len=28}], msg_iovlen=3, msg_controllen=0, msg_flags=0}, MSG_DONTWAIT|MSG_NOSIGNAL) = 45 getsockopt(3, SOL_SOCKET, SO_PEERCRED, {pid=1, uid=0, gid=0}, [12]) = 0 strace: Process 22999 attached [pid 22998] recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="OK fd99f58716884af9a7c053f7d08a1db0\r\nAGREE_UNIX_FD\r\n", iov_len=256}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_NOSIGNAL|MSG_CMSG_CLOEXEC) = 52 [pid 22998] sendmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\1\4\1\5\0\0\0\1\0\0\0\237\0\0\0\1\1o\0,\0\0\0/org/freedesktop/systemd1/unit/ntp_2eservice\0\0\0\0\3\1s\0\6\0\0\0GetAll\0\0\2\1s\0\37\0\0\0org.freedesktop.DBus.Properties\0\6\1s\0\30\0\0\0org.freedesktop.systemd1\0\0\0\0\0\0\0\0\10\1g\0\1s\0\0", iov_len=176}, {iov_base="\0\0\0\0\0", iov_len=5}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_DONTWAIT|MSG_NOSIGNAL) = 181 [pid 22998] recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\2\1\1Q(\0\0\1\0\0\0;\0\0\0\5\1u\0\1\0\0\0", iov_len=24}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_NOSIGNAL|MSG_CMSG_CLOEXEC) = 24 To manage notifications about this bug go to: https://bugs.launchpad.net/ubuntu/+source/dbus/+bug/1885948/+subscriptions -- Mailing list: https://launchpad.net/~touch-packages Post to : touch-packages@lists.launchpad.net Unsubscribe : https://launchpad.net/~touch-packages More help : https://help.launchpad.net/ListHelp