From:   Sachin Sant <redacted>
Date:   Thu, 30 Jun 2022 16:07:06 +0530

quoted

quoted

Yes, the problem can be recreated after login. I have collected the strace
logs.

I confirmed fprintd failed to launch with this message on failure case.

===
ltcden8-lp6 fprintd[2516]: (fprintd:2516): fprintd-WARNING **: 01:56:45.705: Failed to open connection to bus: Could not connect: Connection refused
===


But in the strace log of both cases, only one socket is created and
following connect() completes without an error.  And the peer socket
does not seem to be d-bus one.

===
$ cat working-case/strace-fprintd-service.log | grep "socket("
01:52:08 socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
$ cat working-case/strace-fprintd-service.log | grep "socket(" -A 10
01:52:08 socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
...
01:52:08 connect(3, {sa_family=AF_UNIX, sun_path="/run/systemd/private"}, 22) = 0
...
$ cat not-working-case/strace-fprintd-service.log | grep "socket("
01:58:14 socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
$ cat not-working-case/strace-fprintd-service.log | grep "socket(" -A 10
01:58:14 socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
...
01:58:14 connect(3, {sa_family=AF_UNIX, sun_path="/run/systemd/private"}, 22) = 0
===

So I think the error message part is not traced well.
Could you try to strace directly for the command in ExecStart section of
its unit file?

Thank you for your inputs. This is what I did, changed the ExecStart
line in /usr/lib/systemd/system/fprintd.service to

ExecStart=strace -t -ff /usr/libexec/fprintd

Captured the logs after recreating the problem.
fprintd-pass-strace.log (working case) and
fprintd-strace-fail.log (failing case).

In case of failure I see following:

Jun 30 05:52:41 ltcden8-lp6 strace[5595]: [pid  5599] 05:52:41 connect(5, {sa_family=AF_UNIX, sun_path="/var/run/dbus/system_bus_socket"}, 110) = -1 ECONNREFUSED (Connection refused)
fprintd-fail-strace.log:Jun 30 05:52:41 ltcden8-lp6 strace[5595]: [pid  5599] 05:52:41 sendmsg(5, {msg_name={sa_family=AF_UNIX, sun_path="/run/systemd/journal/socket"}, msg_namelen=29, msg_iov=[{iov_base="GLIB_OLD_LOG_API", iov_len=16}, {iov_base="=", iov_len=1}, {iov_base="1", iov_len=1}, {iov_base="\n", iov_len=1}, {iov_base="MESSAGE", iov_len=7}, {iov_base="=", iov_len=1}, {iov_base="Failed to open connection to bus"..., iov_len=71}, {iov_base="\n", iov_len=1}, {iov_base="PRIORITY", iov_len=8}, {iov_base="=", iov_len=1}, {iov_base="4", iov_len=1}, {iov_base="\n", iov_len=1}, {iov_base="GLIB_DOMAIN", iov_len=11}, {iov_base="=", iov_len=1}, {iov_base="fprintd", iov_len=7}, {iov_base="\n", iov_len=1}], msg_iovlen=16, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = -1 ECONNREFUSED (Connection refused)

For working case connect works

fprintd-pass-strace.log:Jun 30 05:58:18 ltcden8-lp6 strace[2585]: [pid  2658] 05:58:18 connect(5, {sa_family=AF_UNIX, sun_path="/var/run/dbus/system_bus_socket"}, 110) = 0

Thank you for collecting logs!
I will take a look today.

Best regards,
Kuniyuki

- Sachin