[systemd-devel] Cannot start service due to 'systemd-tty-ask-password-agent --watch' not answering

[Yeela Kaplan]

----- Original Message -----
> From: "Lennart Poettering" <lennart at poettering.net>
> To: "Yeela Kaplan" <ykaplan at redhat.com>
> Cc: systemd-devel at lists.freedesktop.org, "Oved Ourfali" <ovedo at redhat.com>
> Sent: Sunday, September 6, 2015 4:56:29 PM
> Subject: Re: [systemd-devel] Cannot start service due to 'systemd-tty-ask-password-agent --watch' not answering
> 
> On Thu, 03.09.15 04:39, Yeela Kaplan (ykaplan at redhat.com) wrote:
> 
> > Hi all,
> > We have run into a problem starting a service on EL7.1.
> > We installed the same environment on two hosts, on the first one the
> > service started successfully and on the second one it failed to start.
> > 
> > On the machine failing when running:
> > systemctl start supervdsmd.service
> > 
> > we see that a child process `systemd-tty-ask-password-agent --watch`
> > is spawned by systemctl:
> >  
> > [root at green-vdsc ~]# pstree -p $$
> > bash(13179)─┬─pstree(13494)
> >             └─systemctl(13440)───systemd-tty-ask(13441)
> > 
> > using strace -f we see that systemctl is waiting on a response from
> > systemd-tty-ask but never receives it and gets stuck forever polling:
> > 
> > [pid 14884] execve("/usr/bin/systemd-tty-ask-password-agent",
> > ["/usr/bin/systemd-tty-ask-passwor"..., "--watch"], [/* 31 vars */]) = 0
> > .
> > .
> > .
> > poll([{fd=3, events=POLLIN}], 1, 100)   = 1 ([{fd=3, revents=POLLIN}])
> > read(3,
> > "\242\233\270\f9\257\326\257_\n\30\264\263\17\32\272\0058\331\245\236f\207\202\321(\322`pS\324\376"...,
> > 120) = 120
> > poll([{fd=3, events=POLLIN}], 1, 100)   = 1 ([{fd=3, revents=POLLIN}])
> > read(3,
> > "G\262_$\210%*\275Q`G\240\361F\323\306\254.\334\323]\314:!u\343H\200\227\1\206&"...,
> > 120) = 120
> > poll([{fd=3, events=POLLIN}], 1, 100)   = 1 ([{fd=3, revents=POLLIN}])
> > read(3,
> > "\272\177J\330D\252\367\2\367w\302\230-\221'\267\365\376\214\217\334\327\245a\311\377\tfc\177\273j"...,
> > 120) = 120
> > poll([{fd=3, events=POLLIN}], 1, 100)   = 1 ([{fd=3, revents=POLLIN}])
> > read(3,
> > "\324\230x\231\222\210\271-\22a\2134\202\274\\\373\305\231;\177\244e\246=k\204\216\327\340iG\17"...,
> > 120) = 120
> > poll([{fd=3, events=POLLIN}], 1, 100)   = 1 ([{fd=3, revents=POLLIN}])
> > read(3,
> > "3\210\234X\0N\202G\354\22WFt^\331V\344\32\\A\36\323[\302\370\363\371\210\211\t\2129"...,
> > 120) = 120
> > poll([{fd=3, events=POLLIN}], 1, 100)   = 1 ([{fd=3, revents=POLLIN}])
> > read(3,
> > "+\235\26\274\373R\34\377Rs9\370\273\370\t),V\276\v`\233^E\256\257lX#\27\23W"...,
> > 120) = 120
> > poll([{fd=3, events=POLLIN}], 1, 100)   = 1 ([{fd=3, revents=POLLIN}])
> > read(3,
> > "\346\237\ru5\311\372\362K?2\203\300\246C2K(\4+\20\341t\4S\370\35\25}>\265\240"...,
> > 120) = 120
> > poll([{fd=3, events=POLLIN}], 1, 100)   = 1 ([{fd=3, revents=POLLIN}])
> > read(3,
> > "F\25\257j\233q\315W\25\334\306\233\217!\306$\255Y\33\364\0039Qy\2\223 at o\235\257hw"...,
> > 120) = 120
> > poll([{fd=3, events=POLLIN}], 1, 100)   = 1 ([{fd=3, revents=POLLIN}])
> > read(3,
> > "\324\316\10k*\332A\253\344^\5y\372\10I\375\216\372\271\277\205\2264\0\35>?]`\263\374\275"...,
> > 120) = 120
> > poll([{fd=3, events=POLLIN}], 1, 100)   = 1 ([{fd=3, revents=POLLIN}])
> > read(3,
> > "\34P\10w\314e\270\226X\t\212\30\"\17.\334\3471\342B\334\272\315\351\367\324k\273S\363\323f"...,
> > 120) = 120
> > poll([{fd=3, events=POLLIN}], 1, 100)   = 1 ([{fd=3, revents=POLLIN}])
> > read(3,
> > "\210\230;\227\31\261\364A\301#\374\311\206?\17\202\2749\340\246\323gm\315\325\361\335K\200\6h\275"...,
> > 120) = 120
> > poll([{fd=3, events=POLLIN}], 1, 100)   = 1 ([{fd=3, revents=POLLIN}])
> > read(3,
> > "i\10Dl\5\312\222\376\10l\37\277X\341CIs\\\"\235{\315|\334\227\10>\246a\5,\36"...,
> > 120) = 120
> > poll([{fd=3, events=POLLIN}], 1, 100)   = 1 ([{fd=3, revents=POLLIN}])
> > 
> > systemctl is waiting for a response from its child process forever and does
> > not close it.
> > As a result, it never even tries to run the start command for our service
> > supervdsm.
> > So it looks like an issue either with systemd or the way our service
> > interacts with systemd.
> > 
> > Is anyone familiar with such an issue or has an idea why it happens and how
> > to fix it?
> 
> This is really a misconception about what
> systemd-tty-ask-password-agent actually does. It's job is to bring
> password queries from system components to the screen while you wait
> for systemctl to finish. This is useful for things like LUKS hdd
> encryption where the system might have to query the user for a
> passphrase to proceed starting units. Other cases where this is used
> is for passphrases of SSL certificates.
> 
> Unless you actually use LUKS or SSL certificates with a passphrase
> (with a web server that supports querying passwords via systemd's
> password querying mechanism), the agent does pretty much nothing.
> 
> The agent is forked off, waits for passwords to be queried, queries
> them when there are any, and then exits when systemctl finishes.
> 
> You can pass --no-ask-password to systemctl to turn off the agent. See
> the man page for details.
> 

Thank you for your response.
I have tried running:  strace -f systemctl --no-ask-password start supervdsmd.service
and it still reproduces. 
but now intead of:
bash(3448)─┬─pstree(3625)
           └─strace(3618)───systemctl(3623)───systemd-tty-ask(3624)

I get:
bash(3448)─┬─pstree(3586)
           └─strace(3564)───systemctl(3569)

Do you know what systemctl is waiting for then?

> Or in short: I doubt that the password agent has anything to do with
> the problem you are running into.
> 
> --
> Lennart Poettering, Red Hat
>