Bug#806291: systemd: systemctl status ignores -n argument

[Zbigniew Jędrzejewski-Szmek]

On Sat, Nov 28, 2015 at 11:37:55AM +0100, Eduard Bloch wrote:
> Hallo,
> * Michael Biebl [Thu, Nov 26 2015, 04:32:43PM]:
> > Am 26.11.2015 um 15:59 schrieb Michael Biebl:
> > > Works here. But I actually need a service which produces more then 10
> > > lines of output when started.
> > 
> > To illustrate what I did:
> > 
> > # cat /etc/systemd/system/output.service
> > [Unit]
> > Description=foo
> > [Service]
> > Type=oneshot
> > ExecStart=/bin/sh -c "for i in `seq 1 200`; do echo $i; done"
> > 
> > 
> > # systemctl start output.service
> > # systemct status -n 100
> > log message 102-200
> > Nov 26 16:28:27 pluto systemd[1]: Started foo.
> 
> You are demonstrating the good case, I am after a bad case. Let's try
> this:
> 
> [Unit]
> Description=SomeThing
> After=network.target
> [Install]
> WantedBy=multi-user.target
> 
> [Service]
> Type=notify
> Restart=on-failure
> ExecStart=/bin/sh -c "echo OMG THEY KILLED KENNY >&2; exit 123"
> 
> and check the result:
> 
>  foo.service - SomeThing
>    Loaded: loaded (/lib/systemd/system/foo.service; disabled; vendor preset: enabled)
>    Active: failed (Result: start-limit) since Sa 2015-11-28 11:28:39 CET; 13s ago
>   Process: 6982 ExecStart=/bin/sh -c echo OMG THEY KILLED KENNY >&2; exit 123 (code=exited, status=123)
>  Main PID: 6982 (code=exited, status=123)
> 
> Nov 28 11:28:39 idefix systemd[1]: Failed to start SomeThing.
> Nov 28 11:28:39 idefix systemd[1]: foo.service: Unit entered failed state.
> Nov 28 11:28:39 idefix systemd[1]: foo.service: Failed with result 'exit-code'.
> Nov 28 11:28:39 idefix sh[6982]: OMG THEY KILLED KENNY
> Nov 28 11:28:39 idefix systemd[1]: foo.service: Service hold-off time over, scheduling restart.
> Nov 28 11:28:39 idefix systemd[1]: Stopped SomeThing.
> Nov 28 11:28:39 idefix systemd[1]: foo.service: Start request repeated too quickly.
> Nov 28 11:28:39 idefix systemd[1]: Failed to start SomeThing.
> Nov 28 11:28:39 idefix systemd[1]: foo.service: Unit entered failed state.
> Nov 28 11:28:39 idefix systemd[1]: foo.service: Failed with result 'start-limit'.
> 
> 
> Looks good, huh? So what is the major difference to the script in the original report?
> Is it maybe this?
> Type=notify

There's a race for short-lived programs - if the process has exited by
the time journald looks the sender up in /proc, it will not be able to
assign the message the right systemd unit. This means that the message
will be in logs, but it will not be shown by
'systemctl status unit'/'journalctl -u unit'. This race is currently
unfixable, until kernel provides additional functionality to attach more
metadata to messages.

So you should check with journalctl -u that the messages you think
should be shown are really attached to that unit.

> I can imagine that if the service dies before any dbus event was sent then the
> messages are printed early, followed by the spam I mentioned? And that makes
> them scroll out of "systemctl status" buffer?
> 
> But anyhow, it's a secondary issue and probably deserves a second bug report.
> The thing that botters me, see subject, is the broken -n option, adding -n20 or
> -n2000 to systemctl-status call does not change anything. It keeps displaying 10
> lines.
That's really strange.
What is the exact command line that you are using?
Does 'systemctl -n0 status ...' show any log lines?
Do you have POSIXLY_CORRECT set?

Zbyszek