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
Touch seeded packages, which is subscribed to systemd in Ubuntu.
https://bugs.launchpad.net/bugs/1456789
Title:
restarting services hangs on systemd-tty-ask-password-agent
Status in systemd package in Ubuntu:
Confirmed
Status in systemd package in Debian:
Fix Released
Bug description:
I have a script run as root from cron that tweaks smb.conf and
restarts smbd and winbind. Problem is, starting today after working
perfectly up till yesterday, this script now hangs on Ubuntu 15.04.
When run from cron, the process tree looks like this:
service smbd restart
\_ systemctl restart smbd.service
\_ /bin/systemd-tty-ask-password-agent --watch
\_ /usr/bin/pkttyagent --notify-fd 5 --fallback
Run from a shell via sudo, same thing except the process tree
(obviously) includes the sudo command. It times out after 5 minutes,
causing the script to fail. If I manually kill the processes, it fails
faster.
The simplest possible scripts that reproduce this, run as root or
through cron or via sudo, are:
#!/bin/sh
service smbd restart
#!/bin/sh
systemctl restart smbd.service
Using 'service', this works perfectly on Ubuntu 14.04 and 14.10, and
until this morning worked perfectly on 15.04 as well.
1) The release of Ubuntu you are using, via 'lsb_release -rd' or System ->
About Ubuntu
Ubuntu 15.04
2) The version of the package you are using, via 'apt-cache policy pkgname'
or by checking in Software Center
systemd 219-7ubuntu5
samba 2:4.1.13+dfsg-4ubuntu3
3) What you expected to happen
Services to restart
4) What happened instead
Services didn't restart, 'systemctl' hung
To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/systemd/+bug/1456789/+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
