[systemd-devel] systemctl runs systemd-tty-ask-password-agent and hangs?

Tue Apr 19 08:06:31 PDT 2011

During this time, systemd does the following:

epoll_wait(4, {{EPOLLIN, {u32=25559008, u64=25559008}}}, 1, 4294967295) = 1
accept4(8, {sa_family=AF_FILE, NULL}, [2], SOCK_CLOEXEC) = 15
fcntl(15, F_GETFL)                      = 0x2 (flags O_RDWR)
fcntl(15, F_SETFL, O_RDWR|O_NONBLOCK)   = 0
getsockname(15, {sa_family=AF_FILE, path="/run/systemd/private"}, [23]) = 0
epoll_ctl(4, EPOLL_CTL_ADD, 15, {0, {u32=27479504, u64=27479504}}) = 0
epoll_ctl(4, EPOLL_CTL_ADD, 15, {EPOLLIN|EPOLLERR|EPOLLHUP,
{u32=27495904, u64=27495904}}) = -1 EEXIST (File exists)
dup(15)                                 = 17
epoll_ctl(4, EPOLL_CTL_ADD, 17, {EPOLLIN|EPOLLERR|EPOLLHUP,
{u32=27495904, u64=27495904}}) = 0
epoll_wait(4, {{EPOLLIN, {u32=27495904, u64=27495904}}}, 1, 4294967295) = 1
recvmsg(15, {msg_name(0)=NULL, msg_iov(1)=[{"\0", 1}],
msg_controllen=0, msg_flags=0}, 0) = 1
getsockopt(15, SOL_SOCKET, SO_PEERCRED, "\311J\0\0\0\0\0\0\0\0\0\0", [12]) = 0
read(15, "AUTH EXTERNAL 30\r\n", 2048)  = 18
epoll_ctl(4, EPOLL_CTL_MOD, 17, {0, {u32=27495904, u64=27495904}}) = 0
epoll_ctl(4, EPOLL_CTL_MOD, 15, {EPOLLOUT|EPOLLERR|EPOLLHUP,
{u32=27479504, u64=27479504}}) = 0
epoll_wait(4, {{EPOLLOUT, {u32=27479504, u64=27479504}}}, 1, 4294967295) = 1
sendto(15, "OK bd2fd1a7339302b7307e9e3100000010\r\n", 37,
MSG_NOSIGNAL, NULL, 0) = 37
epoll_ctl(4, EPOLL_CTL_MOD, 17, {EPOLLIN|EPOLLERR|EPOLLHUP,
{u32=27495904, u64=27495904}}) = 0
epoll_ctl(4, EPOLL_CTL_MOD, 15, {0, {u32=27479504, u64=27479504}}) = 0
epoll_wait(4, {{EPOLLIN, {u32=27495904, u64=27495904}}}, 1, 4294967295) = 1
read(15, "NEGOTIATE_UNIX_FD\r\n", 2048) = 19
epoll_ctl(4, EPOLL_CTL_MOD, 17, {0, {u32=27495904, u64=27495904}}) = 0
epoll_ctl(4, EPOLL_CTL_MOD, 15, {EPOLLOUT|EPOLLERR|EPOLLHUP,
{u32=27479504, u64=27479504}}) = 0
epoll_wait(4, {{EPOLLOUT, {u32=27479504, u64=27479504}}}, 1, 4294967295) = 1
sendto(15, "AGREE_UNIX_FD\r\n", 15, MSG_NOSIGNAL, NULL, 0) = 15
epoll_ctl(4, EPOLL_CTL_MOD, 17, {EPOLLIN|EPOLLERR|EPOLLHUP,
{u32=27495904, u64=27495904}}) = 0
epoll_ctl(4, EPOLL_CTL_MOD, 15, {0, {u32=27479504, u64=27479504}}) = 0
epoll_wait(4, {{EPOLLIN, {u32=27495904, u64=27495904}}}, 1, 4294967295) = 1
read(15, "BEGIN\r\n", 2048)             = 7
epoll_wait(4, {{EPOLLIN, {u32=27495904, u64=27495904}}}, 1, 4294967295) = 1
recvmsg(15, {msg_name(0)=NULL,
msg_iov(1)=[{"l\1\0\1(\0\0\0\1\0\0\0\240\0\0\0\1\1o\0\31\0\0\0/org/freedesktop/systemd1\0\0\0\0\0\0\0\6\1s\0\30\0\0\0org.freedesktop.systemd1\0\0\0\0\0\0\0\0\2\1s\0
\0\0\0org.freedesktop.systemd1.Manager\0\0\0\0\0\0\0\0\3\1s\0\t\0\0\0StartUnit\0\0\0\0\0\0\0\10\1g\0\2ss\0\24\0\0\0mounter at dm-0.service\0\0\0\0\7\0\0\0replace\0emd1.Unit\0\0\0\20\0\0\0NeedDaemonReload\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
2048}], msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC},
MSG_CMSG_CLOEXEC) = 216
recvmsg(15, 0x7fffe366b0c0, MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource
temporarily unavailable)
sendmsg(15, {msg_name(0)=NULL,
msg_iov(2)=[{"l\2\1\1'\0\0\0\1\0\0\0\17\0\0\0\5\1u\0\1\0\0\0\10\1g\0\1o\0\0",
32}, {"\"\0\0\0/org/freedesktop/systemd1/job/1869\0", 39}],
msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 71
epoll_wait(4, {{EPOLLIN, {u32=27495904, u64=27495904}}}, 1, 4294967295) = 1
recvmsg(15, {msg_name(0)=NULL,
msg_iov(1)=[{"l\1\0\1\31\0\0\0\2\0\0\0\227\0\0\0\1\1o\0\31\0\0\0/org/freedesktop/systemd1\0\0\0\0\0\0\0\6\1s\0\30\0\0\0org.freedesktop.systemd1\0\0\0\0\0\0\0\0\2\1s\0
\0\0\0org.freedesktop.systemd1.Manager\0\0\0\0\0\0\0\0\3\1s\0\7\0\0\0GetUnit\0\10\1g\0\1s\0\0\24\0\0\0mounter at dm-0.service\0service\0\0\0\0\7\0\0\0replace\0\0md1.Unit\0\0\0\20\0\0\0NeedDaemonReload\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
2048}], msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC},
MSG_CMSG_CLOEXEC) = 193
recvmsg(15, 0x7fffe366b0c0, MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource
temporarily unavailable)
sendmsg(15, {msg_name(0)=NULL,
msg_iov(2)=[{"l\2\1\1>\0\0\0\2\0\0\0\17\0\0\0\5\1u\0\2\0\0\0\10\1g\0\1o\0\0",
32}, {"9\0\0\0/org/freedesktop/systemd1/unit/mounter_40dm_2d0_2eservice\0",
62}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 94
epoll_wait(4, {{EPOLLIN, {u32=27495904, u64=27495904}}}, 1, 4294967295) = 1
recvmsg(15, {msg_name(0)=NULL,
msg_iov(1)=[{"l\1\0\0019\0\0\0\3\0\0\0\260\0\0\0\1\1o\0009\0\0\0/org/freedesktop/systemd1/unit/mounter_40dm_2d0_2eservice\0\0\0\0\0\0\0\6\1s\0\30\0\0\0org.freedesktop.systemd1\0\0\0\0\0\0\0\0\2\1s\0\37\0\0\0org.freedesktop.DBus.Properties\0\3\1s\0\3\0\0\0Get\0\0\0\0\0\10\1g\0\2ss\0\35\0\0\0org.freedesktop.systemd1.Unit\0\0\0\20\0\0\0NeedDaemonReload\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
2048}], msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC},
MSG_CMSG_CLOEXEC) = 249
recvmsg(15, 0x7fffe366b0c0, MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource
temporarily unavailable)
stat("/etc/systemd/system/mounter at .service", {st_dev=makedev(8, 1),
st_ino=22414401, st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0,
st_blksize=4096, st_blocks=8, st_size=374,
st_atime=2011/04/19-14:48:16, st_mtime=2011/04/19-14:48:07,
st_ctime=2011/04/19-14:48:07}) = 0
sendmsg(15, {msg_name(0)=NULL,
msg_iov(2)=[{"l\2\1\1\10\0\0\0\3\0\0\0\17\0\0\0\5\1u\0\3\0\0\0\10\1g\0\1v\0\0",
32}, {"\1b\0\0\0\0\0\0", 8}], msg_controllen=0, msg_flags=0},
MSG_NOSIGNAL) = 40

and then hangs in an epoll_wait.

On Tue, Apr 19, 2011 at 5:02 PM, Albert Strasheim <fullung at gmail.com> wrote:
> Hello again
>
> I had the same problem again today trying to start a service.
>
> The last few system calls made by systemd-tty-ask-password-agent are:
>
> 19048 mkdir("/run", 0755)               = -1 EEXIST (File exists)
> 19048 mkdir("/run/systemd", 0755)       = -1 EEXIST (File exists)
> 19048 mkdir("/run/systemd/ask-password", 0755) = -1 EEXIST (File exists)
> 19048 inotify_init1(O_CLOEXEC)          = 4
> 19048 inotify_add_watch(4, "/run/systemd/ask-password",
> IN_CLOSE_WRITE|IN_MOVED_TO) = 1
> 19048 rt_sigprocmask(SIG_SETMASK, [INT TERM], NULL, 8) = 0
> 19048 signalfd4(-1, [INT TERM], 8, O_NONBLOCK|O_CLOEXEC) = 5
> 19048 open("/run/systemd/ask-password",
> O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 6
> 19048 getdents(6, {{d_ino=9748, d_off=1, d_reclen=24, d_name="."}
> {d_ino=9747, d_off=2, d_reclen=24, d_name=".."}}, 32768) = 48
> 19048 getdents(6, {}, 32768)            = 0
> 19048 close(6)                          = 0
> 19048 poll([{fd=4, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1) = 1
> ([{fd=5, revents=POLLIN}])
>
> I am running systemd-24-1.fc15.x86_64.
>
> Full trace attached.
>
> Regards
>
> Albert
>
> On Tue, Apr 5, 2011 at 10:06 AM, Albert Strasheim <fullung at gmail.com> wrote:
>> Hello all
>>
>> Sometimes (not sure when), when I run
>>
>> systemctl stop foo.service
>>
>> where foo.service is in this state:
>>
>> foo.service loaded failed failed stop Foo
>>
>> systemctl just hangs. I can see that it has started a process called
>>
>> /bin/systemd-tty-ask-password-agent --watch
>>
>> which is apparently waiting for input of some kind, but I don't know
>> where or what.
>>
>> It hangs until I kill systemctl with Ctrl-C.
>>
>> I'm running systemd-22-1.fc15.x86_64 and upgraded the machine from
>> FC14 using yum distro-sync, if that matters.
>>
>> Regards
>>
>> Albert
>