[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-Id: <DC7D445E-8A04-4104-AF90-6A530CB5FF93@linux.ibm.com>
Date: Thu, 30 Jun 2022 16:07:06 +0530
From: Sachin Sant <sachinp@...ux.ibm.com>
To: Kuniyuki Iwashima <kuniyu@...zon.com>
Cc: davem@...emloft.net, linux-next@...r.kernel.org,
linuxppc-dev@...ts.ozlabs.org, netdev@...r.kernel.org
Subject: Re: [powerpc] Fingerprint systemd service fails to start
(next-20220624)
>>>
>> 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
- Sachin
Download attachment "fprintd-fail-strace.log" of type "application/octet-stream" (68259 bytes)
Download attachment "fprintd-pass-strace.log" of type "application/octet-stream" (104671 bytes)
Powered by blists - more mailing lists