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

Discussion:

Albert Strasheim

2011-04-05 08:06:00 UTC

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

Albert Strasheim

2011-04-19 15:02:51 UTC

Permalink

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

Post by Albert Strasheim
Hello all
Sometimes (not sure when), when I run
systemctl stop foo.service
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

Albert Strasheim

2011-04-19 15:06:31 UTC

Permalink

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\***@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\***@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/***@.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.

Post by Albert Strasheim
Hello again
I had the same problem again today trying to start a service.
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

Albert Strasheim

2011-04-19 15:18:41 UTC

Permalink

Hello

Finally, a clue.

It seems after a really long time, or maybe sometimes, systemctl will print:

A dependency job failed. See system logs for details.

and sometimes (but not always), syslog will contain:

systemd[1]: Job dev-dm-0.device/start timed out.

This is caused by an

After=dev-%i.device

in my .service.

Still strange that things hang for so long though.

Regards

Albert

Lennart Poettering

2011-04-20 00:14:35 UTC

Permalink

Post by Albert Strasheim
Hello
Finally, a clue.
A dependency job failed. See system logs for details.
systemd[1]: Job dev-dm-0.device/start timed out.
This is caused by an
After=dev-%i.device
in my .service.
Still strange that things hang for so long though.

The default timeout is now agt 3min. Maybe we should lower it again to 2min.

Lennart

--
Lennart Poettering - Red Hat, Inc.

Lennart Poettering

2011-04-20 00:13:59 UTC

Permalink

Post by Albert Strasheim
and then hangs in an epoll_wait.

This looks pretty much correct too. We are just waiting for a response
from systemd.

Lennart

--
Lennart Poettering - Red Hat, Inc.

Lennart Poettering

2011-04-20 00:13:20 UTC

Permalink

This looks alright. The agent just creates an inotify on
/run/systemd/ask-password and waits for changes on that.

See http://www.freedesktop.org/wiki/Software/systemd/PasswordAgents for
more information on the precise algorithm.

Lennart

--
Lennart Poettering - Red Hat, Inc.

Christian Hesse

2011-04-20 10:12:38 UTC

Permalink

Post by Albert Strasheim
Hello again
I had the same problem again today trying to start a service.

Hello everybody,

I have the same problem on a number of Arch Linux Systems. The boot process
stalls untill dev-{vg-{home,swap},bt-boot}.device times out after three
minutes. After the system has booted /home and /boot are not mountet, swap is
not activated. Running "systemctl start dev-vg-home.device" times out after
three minutes as well, however I can mount the filesystems manually.

--
Schoene Gruesse
Chris

Lennart Poettering

2011-04-20 14:04:55 UTC

Permalink

Post by Christian Hesse

Post by Albert Strasheim
Hello again
I had the same problem again today trying to start a service.

Hello everybody,
I have the same problem on a number of Arch Linux Systems. The boot process
stalls untill dev-{vg-{home,swap},bt-boot}.device times out after three
minutes. After the system has booted /home and /boot are not mountet, swap is
not activated. Running "systemctl start dev-vg-home.device" times out after
three minutes as well, however I can mount the filesystems manually.

Sounds like LVM borkage.

Note that you need an up-to-date LVM with udev support enabled and it
must be the same version in your initrd as in your main system.

Lennart

--
Lennart Poettering - Red Hat, Inc.

Christian Hesse

2011-04-20 14:35:51 UTC

Permalink

On Wed, 20 Apr 2011 16:04:55 +0200

Post by Lennart Poettering

On Tue, 19 Apr 2011 17:02:51 +0200 Albert Strasheim

Post by Albert Strasheim
Hello again
I had the same problem again today trying to start a service.

Hello everybody,
I have the same problem on a number of Arch Linux Systems. The boot
process stalls untill dev-{vg-{home,swap},bt-boot}.device times out
after three minutes. After the system has booted /home and /boot
are not mountet, swap is not activated. Running "systemctl start
dev-vg-home.device" times out after three minutes as well, however
I can mount the filesystems manually.

Sounds like LVM borkage.
Note that you need an up-to-date LVM with udev support enabled and it
must be the same version in your initrd as in your main system.

This is lvm2-2.02.84-1 and udev-167-1. lvm2 is compiled with these
options (among others):

--with-udevdir=/lib/udev/rules.d/ --enable-udev_sync --enable-udev_rules

So I assume everything should be fine. My initrd is up to date.

Any ideas how to debug this?

--
Schoene Gruesse
Chris

Christian Hesse

2011-04-20 15:01:02 UTC

Permalink

On Wed, 20 Apr 2011 16:35:51 +0200

Post by Christian Hesse
On Wed, 20 Apr 2011 16:04:55 +0200

Post by Lennart Poettering

On Tue, 19 Apr 2011 17:02:51 +0200 Albert Strasheim

Post by Albert Strasheim
Hello again
I had the same problem again today trying to start a service.

Hello everybody,
I have the same problem on a number of Arch Linux Systems. The
boot process stalls untill dev-{vg-{home,swap},bt-boot}.device
times out after three minutes. After the system has booted /home
and /boot are not mountet, swap is not activated. Running
"systemctl start dev-vg-home.device" times out after three
minutes as well, however I can mount the filesystems manually.

Sounds like LVM borkage.
Note that you need an up-to-date LVM with udev support enabled and
it must be the same version in your initrd as in your main system.

This is lvm2-2.02.84-1 and udev-167-1. lvm2 is compiled with these
--with-udevdir=/lib/udev/rules.d/ --enable-udev_sync
--enable-udev_rules
So I assume everything should be fine. My initrd is up to date.
Any ideas how to debug this?

Ok, got one step further I think.
The scripts in my initrd call

$ /sbin/vgchange --sysinit -a y

I think this breaks udev in any way? After calling

$ vgchange -a n && vgchange -a y

everything seems to work fine. I can run

$ systemctl start dev-bt-boot.device

without any delay. So what is acting the wrong way?

--
Schoene Gruesse
Chris

Lennart Poettering

2011-04-20 16:41:33 UTC

Permalink

Post by Christian Hesse
Ok, got one step further I think.
The scripts in my initrd call
$ /sbin/vgchange --sysinit -a y
I think this breaks udev in any way? After calling
$ vgchange -a n && vgchange -a y
everything seems to work fine. I can run
$ systemctl start dev-bt-boot.device
without any delay. So what is acting the wrong way?

Most likely your lvm in the initrd does not match up with the installed
one or the udev db gets lost on the way. This has little to do with
systemd itself btw.

Lennart

--
Lennart Poettering - Red Hat, Inc.

Christian Hesse

2011-04-20 19:33:13 UTC

Permalink

On Wed, 20 Apr 2011 18:41:33 +0200 Lennart Poettering

Post by Lennart Poettering

Most likely your lvm in the initrd does not match up with the installed
one or the udev db gets lost on the way. This has little to do with
systemd itself btw.

The udev db was the problem... My initrd did not handle /run correctly (or at
all). However the fix is very simple: Update to mkinitcpio-0.6.10-1 from
[testing].

Thanks a lot for your help!

--
Schoene Gruesse
Chris

Lennart Poettering

2011-04-20 00:11:52 UTC

Permalink

Post by Albert Strasheim
Hello all
Sometimes (not sure when), when I run
systemctl stop foo.service
foo.service loaded failed failed stop Foo

Would be good to get my hands on an output of "systemctl status
foo.service" (and systemctl show would be cool too) right before this
happens.

Post by Albert Strasheim
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 is started during start and stop to process password queries if there
are any. You can disable this with --no-ask-password.

This is used for cryptodisks and SSL servers (or any service pulling
these) which need a password to start, to unlock the disk or the SSL
certificate. Normally it will just do nothing and be terminated after
systemctl is done. It will only be spawned if systemctl is run on a tty.

Lennart

--
Lennart Poettering - Red Hat, Inc.