Re: [systemd-devel] A way to debug machine shutdown

2020-06-16 Thread Lennart Poettering
On Di, 16.06.20 11:22, darkpenguin (darkpeng...@yandex.com) wrote:

> I would be able to figure it out if systemd told me what is going on.
> This is my main point - maybe it should tell us immediately that "this
> process is stalling the shutdown" or "this thing reloads me too much"?
> And ideally "...Do you want to kill it?".

Uh, interactivity during shutdown is not something I even want to
start with.

Thing is, systemd actually does tell you that, it tells you whcih
session is at fault. I understand you'd want more finegrained info at
that point, and we place that in the logs. Now, in your system there's
a tonload going on, so it's hard to figure out what is the actual
culprit, but you can't hardly complain we give you too few logs, we
give you rather too many...

Anyway we can certainly extend the console status output at shutdown
to show offending processes, but it's not trivial to do so: the thing
is that system shutdown is handled by PID 1, it shuts down all system
services. One of which is your user's service manager, i.e. the
systemd --user instance. Now, if we blindly tell you that it is not
exiting, you might then complain that systemd is at fault, but
actually it is a service under the systemd --user's supervision that
is at fault. But that relationship is something only the systemd
--user instance understands. Now, we could of course ask `systemd
--user` for the output, but that means we'd allow unpriv programs to
log to the system console just like that, which I find highly
problematic...

So, it's not an easy problem. If we indeed want to show more info on
the system console if user programs misbheave during shutdown we need
to figure out a safe way how to do that, that cannot be gamed by said
users to output whatever they want onto the console.

Lennart

--
Lennart Poettering, Berlin
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] A way to debug machine shutdown

2020-06-16 Thread Lennart Poettering
On Mi, 13.05.20 08:34, darkpenguin (darkpeng...@yandex.com) wrote:

> I had trouble trying to paste a 70M text file to fpaste.org; here is the
> gzipped log of the shutdown process instead ('zcat journal.gz | less'
> works where other ways don't).
>
> >> Instead of 90 seconds of "Waiting for session-1.scope ... ", which gives
> >> us next to zero information about the real source of the problem, why
> >> not also mention exactly which process is the problem? Or even
> >> better, a
> >
> > Again, as  mentioned above, we already do that. That's what I wrote
> > above.
>
> What I meant was not exactly this - rather, show the scope status next
> to the "Waiting for Session 1 of user..." message, so that we don't have
> to enable debug, reproduce the problem one more time and then search
> through a 70M log file.
>
> By the way, I could probably do a "systemctl status session-1.scope"
> from the debug shell, but there is no way to have the debug shell during
> shutdown, is there?..

Hmm, I started having a look at the output, but there's just too much
noise going on, something is reloading PID 1 configuration repeatedly
during shutdown. Please figure out what does that and fix that. It's
not how this should work...

Lennart

--
Lennart Poettering, Berlin
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] A way to debug machine shutdown

2020-05-12 Thread Lennart Poettering
On Di, 12.05.20 11:09, darkpenguin (darkpeng...@yandex.com) wrote:

> > Current versions (since ~231 iirc) of systemd log about the processes
> > they kill due to timeouts. You should find that in the logs.
>
> Package: systemd
> Version: 241-7~deb10u3
>
> I wanted to make sure I'm not missing something about the intended way
> to troubleshoot problems like those. Seems like I'm not.
>
> In my case, it's hard to pinpoint: different processes every time, and
> no information about what's going on. It would have been trivial if
> systemd had more useful outputs, which is what I want to suggest.

Please turn on debug logging "systemd-analyze log-level debug", then
reproduce the issue, and paste the generated logs somewhere
(fpaste.org or so).

> Instead of 90 seconds of "Waiting for session-1.scope ... ", which gives
> us next to zero information about the real source of the problem, why
> not also mention exactly which process is the problem? Or even
> better, a

Again, as  mentioned above, we already do that. That's what I wrote
above.

> tree of what's still alive in that scope. And the last few lines in the
> problematic process' log to see the problem from their side. And/or a
> hint about what command to run to see this information later. (I could
> not find a way to see the service logs from yesterday in 'man
> systemctl', and seeing the scope tree from this moment in the logs is
> hardly possible, so being able to see it on the screen for 90 seconds
> and then never see it again is the best we can do.)

"journalctl" is the way to access logs on systemd systems. Please have
a look there, or paste them so that we can have a look.

Lennart

--
Lennart Poettering, Berlin
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] A way to debug machine shutdown

2020-05-06 Thread Lennart Poettering
On So, 26.04.20 19:08, Dark Penguin (darkpeng...@yandex.com) wrote:

> Very often I have encountered one problem: during shutdown, systemd has
> to wait for something. Of course, it is probably different things every
> time, and it is probably not systemd's fault, at least some of the cases.
>
> This leads to the question: how do we find out the root of the problem?
> Systemd has a lot of good tools for debugging, but using them is not as
> easy as it seems, and the Internet is not much help either.
>
> Naturally, reading the output and the journal would be the first step.
> On the screen, it was "A stop job is running for session 1 of user
> myuser". In the journal, there is:
>
> Apr 26 18:46:56 DEUS systemd[1]: session-1.scope: Stopping timed out.
> Killing.
> Apr 26 18:46:56 DEUS systemd[1]: session-1.scope: Failed with result
> 'timeout'.
> Apr 26 18:46:56 DEUS systemd[1]: Stopped Session 1 of user myuser.
> Apr 26 18:46:56 DEUS systemd[1]: Stopping Login Service...
> Apr 26 18:46:56 DEUS systemd[1]: Stopping User Manager for UID 1000...
> Apr 26 18:46:56 DEUS systemd-logind[809]: Removed session 1.
>
> Now how do I check exactly what was the problem in that session?

Which systemd version is this?

Current versions (since ~231 iirc) of systemd log about the processes
they kill due to timeouts. You should find that in the logs.

There's also:

https://freedesktop.org/wiki/Software/systemd/Debugging/#index2h1

Lennart

--
Lennart Poettering, Berlin
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/systemd-devel


[systemd-devel] A way to debug machine shutdown

2020-04-26 Thread Dark Penguin
Very often I have encountered one problem: during shutdown, systemd has
to wait for something. Of course, it is probably different things every
time, and it is probably not systemd's fault, at least some of the cases.

This leads to the question: how do we find out the root of the problem?
Systemd has a lot of good tools for debugging, but using them is not as
easy as it seems, and the Internet is not much help either.

Naturally, reading the output and the journal would be the first step.
On the screen, it was "A stop job is running for session 1 of user
myuser". In the journal, there is:

Apr 26 18:46:56 DEUS systemd[1]: session-1.scope: Stopping timed out.
Killing.
Apr 26 18:46:56 DEUS systemd[1]: session-1.scope: Failed with result
'timeout'.
Apr 26 18:46:56 DEUS systemd[1]: Stopped Session 1 of user myuser.
Apr 26 18:46:56 DEUS systemd[1]: Stopping Login Service...
Apr 26 18:46:56 DEUS systemd[1]: Stopping User Manager for UID 1000...
Apr 26 18:46:56 DEUS systemd-logind[809]: Removed session 1.

Now how do I check exactly what was the problem in that session?


-- 
darkpenguin
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/systemd-devel