I am running into this problem on Ubuntu 20.04.3 LTS (focal) when
running `dpkg --configure -a`, which is hanging when setting up `base-
files`. From diagnosis so far, it appears `dpkg --configure -a` runs
`/var/lib/dpkg/info/base-files.postinst`, which runs `deb-systemd-invoke
start motd-news.timer`, which executes `systemd-tty-ask-password-agent
--watch`, which waits forever (without asking for a password on the
terminal).  Detailed diagnosis:

$ sudo strace -o /tmp/dpkg-strace -tt -ff dpkg --debug=222 --configure -a
Setting up base-files (11ubuntu5.4) ...
D000002: fork/exec /var/lib/dpkg/info/base-files.postinst ( configure 
11ubuntu5.3 )

Running this `postinst` script manually with `bash -xv` hangs while
executing `deb-systemd-invoke start motd-news.timer`, something also
revealed by `pstree` (for a case running without strace):

bash───sudo───dpkg───base-files.post───systemctl───systemd-tty-ask

Strace outputs around 10k lines.  One of the strace output files, which
appears to correspond to the command `deb-systemd-invoke start motd-
news.timer`, ends with a `ppoll`, apparently waiting for a socket.
Selection from `deb-systemd-invoke start motd-news.timer` (PID 51072):

10:50:46.673278 close(10)               = 0
10:50:46.673319 execve("/usr/bin/deb-systemd-invoke", ["deb-systemd-invoke", 
"start", "motd-news.timer"], 0x56297d000c88 /* 37 vars */) = 0
10:50:46.673511 brk(NULL)               = 0x55fff0539000
10:50:46.673534 arch_prctl(0x3001 /* ARCH_??? */, 0x7ffd593b7540) = -1 EINVAL 
(Invalid argument)
10:50:46.673574 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or 
directory)
10:50:46.673613 openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
10:50:46.673641 fstat(3, {st_mode=S_IFREG|0644, st_size=160254, ...}) = 0
10:50:46.673663 mmap(NULL, 160254, PROT_READ, MAP_PRIVATE, 3, 0) = 
0x7f3bdfb5e000
10:50:46.673686 close(3)                = 0
10:50:46.673713 openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libdl.so.2", 
O_RDONLY|O_CLOEXEC) = 3
[...]
10:50:46.708457 socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
[...]
10:50:46.710298 sendmsg(3, {msg_name=NULL, msg_namelen=0, 
msg_iov=[{iov_base="l\1\4\1\24\0\0\0\2\0\0\0\227\0\0\0\1\1o\0\31\0\0\0/org/fre"...,
 iov_len=168}, {iov_base="\17\0\0\0motd-news.timer\0", iov_len=20}], 
msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_DONTWAIT|MSG_NOSIGNAL) = 188
10:50:46.710350 recvmsg(3, {msg_name=NULL, msg_namelen=0, 
msg_iov=[{iov_base="l\2\1\0017\0\0\0\3\0\0\0007\0\0\0\5\1u\0\2\0\0\0", 
iov_len=24}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, 
MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 24
10:50:46.710422 recvmsg(3, {msg_name=NULL, msg_namelen=0, 
msg_iov=[{iov_base="\7\1s\0\30\0\0\0org.freedesktop.systemd1"..., 
iov_len=103}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, 
MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 103
10:50:46.710472 sendmsg(3, {msg_name=NULL, msg_namelen=0, 
msg_iov=[{iov_base="l\1\4\19\0\0\0\3\0\0\0\250\0\0\0\1\1o\0002\0\0\0/org/fre"...,
 iov_len=184}, {iov_base="\35\0\0\0org.freedesktop.systemd1.Uni"..., 
iov_len=57}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, 
MSG_DONTWAIT|MSG_NOSIGNAL) = 241
10:50:46.710522 recvmsg(3, {msg_namelen=0}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = -1 
EAGAIN (Resource temporarily unavailable)
10:50:46.710565 ppoll([{fd=3, events=POLLIN}], 1, {tv_sec=24, 
tv_nsec=999957000}, NULL, 8) = 1 ([{fd=3, revents=POLLIN}], left {tv_sec=24, 
tv_nsec=999940266})
10:50:46.710626 recvmsg(3, {msg_name=NULL, msg_namelen=0, 
msg_iov=[{iov_base="l\2\1\1\10\0\0\0\4\0\0\0007\0\0\0\5\1u\0\3\0\0\0", 
iov_len=24}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, 
MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 24
10:50:46.710676 recvmsg(3, {msg_name=NULL, msg_namelen=0, 
msg_iov=[{iov_base="\7\1s\0\30\0\0\0org.freedesktop.systemd1"..., iov_len=56}], 
msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, 
MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 56
10:50:46.710745 recvmsg(3, {msg_namelen=0}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = -1 
EAGAIN (Resource temporarily unavailable)
10:50:46.710794 ppoll([{fd=3, events=POLLIN}], 1, NULL, NULL, 8

Another, `systemd-tty-ask-password-agent --watch`,  ends with `poll`,
apparently waiting for a socket or inotify event for a password to
appear.  Selection for 51076:

10:50:46.709061 set_robust_list(0x7fb46e4f98e0, 24) = 0
10:50:46.709158 prctl(PR_SET_NAME, "(sd-askpwagent)"...) = 0
10:50:46.709242 geteuid()               = 0
10:50:46.709322 mmap(NULL, 4096, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb46e9cd000
10:50:46.709349 prctl(PR_SET_MM, PR_SET_MM_ARG_START, 0x7fb46e9cd000, 0, 0) = 0
10:50:46.709371 prctl(PR_SET_MM, PR_SET_MM_ARG_END, 0x7fb46e9cd010, 0, 0) = 0
10:50:46.709393 prctl(PR_SET_PDEATHSIG, SIGTERM) = 0
10:50:46.709416 rt_sigaction(SIGHUP, {sa_handler=SIG_DFL, sa_mask=[], 
sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fb46e808210}, NULL, 8) = 0
10:50:46.709439 rt_sigaction(SIGINT, {sa_handler=SIG_DFL, sa_mask=[], 
sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fb46e808210}, NULL, 8) = 0
10:50:46.709459 rt_sigaction(SIGQUIT, {sa_handler=SIG_DFL, sa_mask=[], 
sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fb46e808210}, NULL, 8) = 0
[...]
10:50:46.711627 prlimit64(0, RLIMIT_NOFILE, NULL, {rlim_cur=512*1024, 
rlim_max=512*1024}) = 0
10:50:46.711660 prlimit64(0, RLIMIT_NOFILE, {rlim_cur=1024, rlim_max=512*1024}, 
NULL) = 0
10:50:46.711690 execve("/bin/systemd-tty-ask-password-agent", 
["/bin/systemd-tty-ask-password-ag"..., "--watch"], 0x7ffce60ac808 /* 37 vars 
*/) = 0
10:50:46.711926 brk(NULL)               = 0x55abfc744000
10:50:46.711956 arch_prctl(0x3001 /* ARCH_??? */, 0x7ffe7027e8f0) = -1 EINVAL 
(Invalid argument)
[...]
10:50:46.722618 read(3, "", 1024)       = 0
10:50:46.722637 close(3)                = 0
10:50:46.722659 stat("/run/systemd/ask-password-block", {st_mode=S_IFDIR|0700, 
st_size=160, ...}) = 0
10:50:46.722683 mknod("/run/systemd/ask-password-block/136:6", S_IFIFO|0600) = 
-1 EEXIST (File exists)
10:50:46.722706 openat(AT_FDCWD, "/run/systemd/ask-password-block/136:6", 
O_RDONLY|O_NOCTTY|O_NONBLOCK|O_CLOEXEC) = 3
10:50:46.722728 stat("/run/systemd", {st_mode=S_IFDIR|0755, st_size=520, ...}) 
= 0
10:50:46.722751 mkdir("/run/systemd/ask-password", 0755) = -1 EEXIST (File 
exists)
10:50:46.722779 stat("/run/systemd/ask-password", {st_mode=S_IFDIR|0755, 
st_size=40, ...}) = 0
10:50:46.722803 rt_sigprocmask(SIG_SETMASK, [TERM], NULL, 8) = 0
10:50:46.722823 signalfd4(-1, [TERM], 8, SFD_CLOEXEC|SFD_NONBLOCK) = 4
10:50:46.722845 inotify_init1(IN_CLOEXEC) = 5
10:50:46.722865 inotify_add_watch(5, "/run/systemd/ask-password", 
IN_CLOSE_WRITE|IN_MOVED_TO) = 1
10:50:46.722891 openat(AT_FDCWD, "/run/systemd/ask-password", 
O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 6
10:50:46.722913 fstat(6, {st_mode=S_IFDIR|0755, st_size=40, ...}) = 0
10:50:46.722937 getdents64(6, /* 2 entries */, 32768) = 48
10:50:46.722959 getdents64(6, /* 0 entries */, 32768) = 0
10:50:46.722977 close(6)                = 0
10:50:46.722995 poll([{fd=4, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1

The main process and the script base-files.postinst appear to be waiting
with `wait4` for other processes to finish:

10:50:46.017699 execve("/usr/bin/dpkg", ["dpkg", "--configure", "-a"], 
0x7fffb1462800 /* 27 vars */) = 0
10:50:46.018044 brk(NULL)               = 0x5636a8783000
10:50:46.018135 arch_prctl(0x3001 /* ARCH_??? */, 0x7fffa60dac50) = -1 EINVAL 
(Invalid argument)
10:50:46.018208 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or 
directory)
10:50:46.018264 openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
10:50:46.018307 fstat(3, {st_mode=S_IFREG|0644, st_size=160254, ...}) = 0
10:50:46.018343 mmap(NULL, 160254, PROT_READ, MAP_PRIVATE, 3, 0) = 
0x7fa02ba19000
10:50:46.018377 close(3)                = 0
10:50:46.018416 openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libselinux.so.1", 
O_RDONLY|O_CLOEXEC) = 3
10:50:46.018450 read(3, 
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@p\0\0\0\0\0\0"..., 832) = 832
[...]
10:50:46.163945 fcntl(5, F_SETFD, FD_CLOEXEC) = 0
10:50:46.164043 fstat(5, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
10:50:46.164180 write(5, "#padding\n#padding\n#padding\n#padd"..., 4096) = 4096
10:50:46.164354 write(5, "padding\n#padding\n#padding\n#paddi"..., 512) = 512
10:50:46.164486 lseek(5, 0, SEEK_SET)   = 0
10:50:46.164598 stat("/var/lib/dpkg/info/base-files.postinst", 
{st_mode=S_IFREG|0755, st_size=5664, ...}) = 0
10:50:46.164718 clone(child_stack=NULL, 
flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, 
child_tidptr=0x7fa02b7406d0) = 51032
10:50:46.165711 rt_sigaction(SIGQUIT, {sa_handler=SIG_IGN, sa_mask=[], 
sa_flags=SA_RESTORER, sa_restorer=0x7fa02b840210}, {sa_handler=SIG_DFL, 
sa_mask=[], sa_flags=0}, 8) = 0
10:50:46.165855 rt_sigaction(SIGINT, {sa_handler=SIG_IGN, sa_mask=[], 
sa_flags=SA_RESTORER, sa_restorer=0x7fa02b840210}, {sa_handler=SIG_DFL, 
sa_mask=[], sa_flags=0}, 8) = 0
10:50:46.166017 wait4(51032,

and

10:50:46.165943 set_robust_list(0x7fa02b7406e0, 24) = 0
10:50:46.166455 chdir("/")              = 0
10:50:46.166748 execve("/var/lib/dpkg/info/base-files.postinst", 
["/var/lib/dpkg/info/base-files.po"..., "configure", "11ubuntu5.3"], 
0x5636a87c4840 /* 36 vars */) = 0
10:50:46.168230 brk(NULL)               = 0x56297cffd000
10:50:46.168542 arch_prctl(0x3001 /* ARCH_??? */, 0x7fffc0915d90) = -1 EINVAL 
(Invalid argument)
10:50:46.168877 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or 
directory)
10:50:46.169322 openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
10:50:46.169734 fstat(3, {st_mode=S_IFREG|0644, st_size=160254, ...}) = 0
10:50:46.169951 mmap(NULL, 160254, PROT_READ, MAP_PRIVATE, 3, 0) = 
0x7f5c7351e000
10:50:46.170127 close(3)                = 0
[...]
10:50:46.673001 close(1)                = 0
10:50:46.673018 fcntl(11, F_SETFD, FD_CLOEXEC) = 0
10:50:46.673035 dup2(3, 1)              = 1
10:50:46.673051 close(3)                = 0
10:50:46.673068 stat("/usr/local/sbin/deb-systemd-invoke", 0x7fffc09159a0) = -1 
ENOENT (No such file or directory)
10:50:46.673093 stat("/usr/local/bin/deb-systemd-invoke", 0x7fffc09159a0) = -1 
ENOENT (No such file or directory)
10:50:46.673113 stat("/usr/sbin/deb-systemd-invoke", 0x7fffc09159a0) = -1 
ENOENT (No such file or directory)
10:50:46.673132 stat("/usr/bin/deb-systemd-invoke", {st_mode=S_IFREG|0755, 
st_size=4430, ...}) = 0
10:50:46.673156 clone(child_stack=NULL, 
flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, 
child_tidptr=0x7f5c7351d850) = 51072
10:50:46.673267 wait4(-1,

Most others end with "+++ exited with 0 +++", and/or I don't see
anything suspicious.

It appears that `deb-systemd-invoke start motd-news.timerdeb-systemd-invoke 
start motd-news.timer` appear to be waiting forever for a password, but no 
request is visible in the user interface.
According to [this blog 
note](https://random.kakaopor.hu/systemd-tty-ask-hangs/), rebooting should 
solve this problem:

> It is rather annoying when systemd-tty-ask or /bin/systemd-tty-ask-
password-agent –watch hangs during a package installation, service start
or stop operation.

> Although rebooting system solves the problem, fortunately it is enough
to restart the systemd manager only:

> ```bash
> sudo systemctl daemon-reexec
> ```

> I suspect this is a systemd bug as daemon-reexec said to be doing
nothing special apart from restarting the daemon with the config reread.

However, neither executing `sudo systemctl daemon-reexec` nor rebooting
the system resolved the problem.  I asked a question on askubuntu.com
(https://askubuntu.com/q/1365845/36831) and also found a closely related
question (https://askubuntu.com/q/1287650/36831) but no satisfactory
solution is proposed there (I would like to believe there is no need to
reinstall the system).  Otherwise I hardly find any relevant or recent
results for others having this problem, so I suspect there's something
off or unusual in my configuration that's triggering the problem.

Is this useful additional information for the bug report here, or should
I file a separate bug report?  Is there any known workaround short of
reinstalling the system?

-- 
You received this bug notification because you are a member of Ubuntu
Bugs, which is subscribed to Ubuntu.
https://bugs.launchpad.net/bugs/1456789

Title:
  restarting services hangs on systemd-tty-ask-password-agent

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/systemd/+bug/1456789/+subscriptions


-- 
ubuntu-bugs mailing list
[email protected]
https://lists.ubuntu.com/mailman/listinfo/ubuntu-bugs

Reply via email to