<div dir="ltr">Next reboot after the user@0.service start/stop cycle was a quick one. It looks as something gets messed up upon logging in. And if not resolved, the system has problems shutting down.</div><div class="gmail_extra">
<br><br><div class="gmail_quote">On 4 October 2013 19:31, Toms Seisums <span dir="ltr"><<a href="mailto:toms.seisums@gmail.com" target="_blank">toms.seisums@gmail.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<div dir="ltr">@Andrey, the full log can be found here, the link was there before also: <a href="http://pastebin.com/wbr04AQw" target="_blank">http://pastebin.com/wbr04AQw</a> (systemd-207)<div>It's quite silent about the cause for the timeout, though.</div>
<div><br></div><div>I've been debugging this for three days now, and I've crystallized a little bit of information.</div><div><br></div><div>1. If I boot the system and stay on login screen, no matter when I hit Ctrl+Alt+Del (ASAP or after an hour), the system will always reboot normally.</div>
<div>2. If I login, and instantly type `reboot`, in about 75% the system will reboot normally, the other 25% being slow, resulting in user@0.service timeout.</div><div>2.1. If I login and wait for some time, the next reboot is going to be slow.</div>
<div>3. I'm using Arch, and they had a bug report already there - <a href="https://bugs.archlinux.org/task/37007" target="_blank">https://bugs.archlinux.org/task/37007</a>, it has come down to that systemd-208 fixes it, though, I've updated and the problem still remains.</div>
<div>4. I've attempted numerous daemon configurations, but the results are inconsistent. Due to that Arch issue being closed and not reopened, I did this, in order to find out whether running daemons aren't at fault.</div>
<div>4.1. I, for some reboot's disabled every daemon (not also running them after the system booted up), and the reboots/shutdowns were still slow.</div><div>4.1.1. The Ctrl+Alt+Del before logging in, is still fast.</div>
<div>5. Downgrading to systemd-204 works flawlessly, also removing the issue that's described in next point.</div>6. Whenever I boot with systemd-207 or systemd-208 and login, I am presented with:<br><br> Failed to open private bus connection: Failed to connect to socket /run/user/0/dbus/user_bus_socket: No such file or directory<div>
<br></div><div>6.1. The issue appears to already be reported by @Andrey - here: <a href="http://lists.freedesktop.org/archives/systemd-devel/2013-September/013393.html" target="_blank">http://lists.freedesktop.org/archives/systemd-devel/2013-September/013393.html</a></div>
<div>7. Apparently, I specially set up a system running in VBox, also an Arch Linux, that didn't have the problem neither running with systemd-207, neither has it with systemd-208 (that actually led me to disable the daemons).</div>
<div>7.1. I did encounter it once though, but since then, it hasn't happened.</div><div>8. If, before running shutdown, I manually: `systemctl stop user@0.service`, the system shuts down prefectly.</div><div><div><br>
</div><div>Here are some logs of shutdown with systemd-208:</div></div><div><br></div><div> 1. Quick, Ctrl+Alt+Del before logging in. (1: <a href="http://pastebin.com/5X0sUHCV" target="_blank">http://pastebin.com/5X0sUHCV</a>)</div>
<div>
2. Slow, executed a little later after logging in. (2: <a href="http://pastebin.com/tjnLNJKH" target="_blank">http://pastebin.com/tjnLNJKH</a>)</div><div> 3. Slow, executed by Ctrl+Alt+Del after logging in, doing some tasks, then `logout`. (3: <a href="http://pastebin.com/4hEmRYen" target="_blank">http://pastebin.com/4hEmRYen</a>)</div>
<div> 4. I wanted to catch a fast reboot with a full login and full daemons running, but couldn't manage to - they all were slow.</div><div> 5. It also happens if I log in with a different user than root and push Ctrl+Alt+Del. (4: <a href="http://pastebin.com/U36WqDzP" target="_blank">http://pastebin.com/U36WqDzP</a>)</div>
<div> 5.1. This is just a test for you @Lennart, just to see if a different user changes anything.</div><div> 6. `systemctl stop user@0.service` to `reboot`, that results in a quick one. (5: <a href="http://pastebin.com/aJ0s32MR" target="_blank">http://pastebin.com/aJ0s32MR</a>) (I, for a second thought that Apache might be causing some issues, because it almost always gets killed, so, I disabled it for some tests, this log has no Apache information - that's just in case you're wondering why the logs don't match. More on Apache adventures below...)</div>
<div> 6.1. I reran it after Apache tests to clarify, quick reboot the first time (9: <a href="http://pastebin.com/HcUA72AE" target="_blank">http://pastebin.com/HcUA72AE</a>). The second time. (10: <a href="http://pastebin.com/rf96QiGA" target="_blank">http://pastebin.com/rf96QiGA</a>) The third time. (11: <a href="http://pastebin.com/bpFu1sQK" target="_blank">http://pastebin.com/bpFu1sQK</a>) All in a row. I did 2 more to test for the next point, all quick.</div>
<div> 6.2. This doesn't seem to change the SFTP behavior, though.</div><div><br></div><div>An extra piece of information I can provide, is that, this appears to happen to break SFTP. If I boot, then connect from my other PC with SFTP (as root), and initiate a reboot from tty0, my SFTP connection will not be dropped. It will actually never even timeout. I could restart my Linux machine for about 100times, and the SFTP window will not even blink, thinking that it's connected. Only when I refresh the SFTP window, I get an error message, asking me to reconnect. With systemd-204 there is no such an issue - it disconnects immediately. Though, on my VBox Arch, there wasn't such an issue with systemd-207, nor with systemd-208.</div>
<div><br></div><div><br></div><div>And @Lennart, you asked, I delivered, here is a log with user@0.service start/stop with 0.5second intervals between start/stop calls. I stripped the booting sequence, starting the log off at about where the system ended it's boot. (12: <a href="http://sharetext.org/zJc" target="_blank">http://sharetext.org/zJc</a>, the link is different because I exceeded pastebins free limit, doh).</div>
<div>Nothing special there, except that dbus thingy.</div><div><br></div><div>---</div><div><br></div><div>Apache:</div><div><br></div><div>So, noticing that Apache gets killed most of time, and systemd-204 also had some delays where it waited for Apache to exit, I thought that the problem is with Apache.</div>
<div><br></div><div>I started this debugging scenario by simply doing a "systemctl stop httpd" into "reboot", that made my system to reboot quickly. (6: <a href="http://pastebin.com/4NgxVAeP" target="_blank">http://pastebin.com/4NgxVAeP</a>)</div>
<div><br></div><div>Though, one `httpd` instance still remains (occasionally, when I "systemctl stop httpd", "ps aux" immediately after - will still display one httpd process), that appears to actually be a bug in Apache's (I guess), that appears to be the one that has to be explicitly killed at the end of reboot process.</div>
<div><br></div><div>By partially confirming, that this is because of Apache, I stopped it upon next boot, disabled it, and rebooted. Starting freshly with "ps aux" reporting no signs of httpd, I attempted to "reboot" - guess what? That's a long one. Three times in a row with no httpd upon boot - all reboots were long, I guess that's not Apache then.</div>
<div><br></div><div>While writing the above and debugging, after having enabled Apache back and stopping it upon boot, even though previous reboots executed immediately, one didn't. (7: <a href="http://pastebin.com/3FnikCX9" target="_blank">http://pastebin.com/3FnikCX9</a>) Apparently the next one after it also didn't. (8: <a href="http://pastebin.com/pnWhuQWC" target="_blank">http://pastebin.com/pnWhuQWC</a>)</div>
<div><br></div><div>---</div><div><br></div><div>P.S. While debugging this, and trying to link some of the problems to some of the daemons, I'm starting to feel as if I'd hit a delusion spree. While occasionally it reboots fast, it might as well be just the random quick-reboot I've been hunting before. Just that stopping those daemons makes me think the problem is tied to them.</div>
<div><br></div><div><br></div><div>---</div><div><br></div><div>Loads of information, some of it are probably total duplicates, but I hope I've given enough and that you'll be able to understand what I've provided. More importantly, I hope that this will help to resolve these issues.</div>
</div><div class="gmail_extra"><div><div class="h5"><br><br><div class="gmail_quote">On 1 October 2013 03:43, Lennart Poettering <span dir="ltr"><<a href="mailto:lennart@poettering.net" target="_blank">lennart@poettering.net</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div><div>On Mon, 30.09.13 18:55, Toms Seisums (<a href="mailto:toms.seisums@gmail.com" target="_blank">toms.seisums@gmail.com</a>) wrote:<br>
<br>
> It appears that history repeats itself.<br>
><br>
> Once (July 2013) a similar issue was reported here, by different user:<br>
> <a href="http://lists.freedesktop.org/archives/systemd-devel/2013-July/012283.html" target="_blank">http://lists.freedesktop.org/archives/systemd-devel/2013-July/012283.html</a><br>
><br>
> I'm also using Arch Linux, systemd-207, linux-3.11.2.<br>
><br>
> On shutdown and reboot, user@0.service occasionally freezes my system until<br>
> it times out and gets killed.<br>
><br>
> Steps to reproduce:<br>
> 1) Boot<br>
> 2) Login<br>
> 3) Execute either systemctl reboot or reboot or shutdown -h now or whatever.<br>
><br>
> I've went through the steps here, to get a proper shutdown log:<br>
> <a href="http://freedesktop.org/wiki/Software/systemd/Debugging/#shutdowncompleteseventually" target="_blank">http://freedesktop.org/wiki/Software/systemd/Debugging/#shutdowncompleteseventually</a><br>
><br>
> And, the shutdown log can be found here: <a href="http://pastebin.com/wbr04AQw" target="_blank">http://pastebin.com/wbr04AQw</a><br>
><br>
> The actual lines related to issue:<br>
><br>
> #2223 [ 74.387130] systemd[1]: Got D-Bus request:<br>
> org.freedesktop.DBus.Local.Disconnected() on /org/freedesktop/DBus/Local<br>
> #2224 [ 163.814925] systemd[1]: user@0.service stopping timed out. Killing.<br>
> #2225 [ 163.815447] systemd[1]: user@0.service changed stop-sigterm -><br>
> stop-sigkill<br>
> #2226 [ 163.816063] systemd[1]: Received SIGCHLD from PID 326 (systemd).<br>
> #2227 [ 163.816093] systemd[1]: Got SIGCHLD for process 326 (systemd)<br>
> #2228 [ 163.816153] systemd[1]: Child 326 died (code=killed, status=9/KILL)<br>
> #2229 [ 163.816158] systemd[1]: Child 326 belongs to user@0.service<br>
> #2230 [ 163.816171] systemd[1]: user@0.service: main process exited,<br>
> code=killed, status=9/KILL<br>
> #2231 [ 163.816183] systemd[1]: user@0.service changed stop-sigkill -><br>
> failed<br>
><br>
> I currently haven't found out a pattern for this. I have attempted to quit<br>
> some processes before initiating the shutdown/reboot, but the result is<br>
> random.<br>
><br>
> About 95% of shutdowns/reboots it will be a long one.<br>
> 3% it will be noticeably longer than the quickest one, but shorter than the<br>
> above one.<br>
> Remaining 2%, the shutdown will be very quick.<br>
<br>
</div></div>Hmm, this is the systemd user instance for root which fails to shut<br>
down. Can you reproduce this if you start/stop "user@0.service" quickly<br>
in a loop?<br>
<span><font color="#888888"><br>
Lennart<br>
<br>
--<br>
Lennart Poettering - Red Hat, Inc.<br>
</font></span></blockquote></div><br><br clear="all"><div><br></div></div></div><div class="im">-- <br><div dir="ltr"><div>Toms Seisums</div><div><br></div><div>- (+371) 26431391</div><div><br></div><div>May the force be with you, always!
</div></div>
</div></div>
</blockquote></div><br><br clear="all"><div><br></div>-- <br><div dir="ltr"><div>Toms Seisums</div><div><br></div><div>- (+371) 26431391</div><div><br></div><div>May the force be with you, always!
</div></div>
</div>