Bug 1841537

(In reply to Pierre Ossman from comment #0)

I'm sorry, but I cannot reconcile

> This means that we lose all log output, which is a major
> pain.

with

> Actual results:
> Log output in the journal.

So there's no log output loss after all?

Sorry, I got "Actual" and "Expected" mixed up. It should have been:

Actual results:
No log output as stderr is always redirected to /dev/null.

Expected results:
Log output in the journal.

Cannot reproduce with a simple test service:

# cat /etc/systemd/system/test.socket
[Socket]
ListenStream=5900
Accept=yes

# cat /etc/systemd/system/test@.service
[Service]
ExecStart=-/usr/bin/bash -c 'echo >&2 "My hovercraft is full of eels."'
User=nobody
StandardError=syslog

# systemctl daemon-reload
# systemctl start test.socket
# nc -z localhost 5900
# journalctl -n 1
-- Logs begin at Fri 2020-06-26 13:01:12 CEST, end at Fri 2020-06-26 13:34:25 CEST. --
Jun 26 13:34:25 localhost.localdomain bash[2455]: My hovercraft is full of eels.

The fact that bash works doesn't really solve the reported case though. Have you tested the setup with Xvnc?

(In reply to Pierre Ossman from comment #4)
> The fact that bash works doesn't really solve the reported case though. Have
> you tested the setup with Xvnc?

The fact that bash works shows there's no problem in systemd. That's all I care for.

I will try to investigate what's going on.

I saw the upstream bug which made you to report this issue: https://github.com/TigerVNC/tigervnc/issues/1023.

I wonder why using "-Log *:stderr:30" makes it to report the log correctly, because it should be already used (it's default value according to documentation).

To me it looks like an issue in Tigervnc itself as using the above mentioned option makes it work (even for me).

Ah, I hadn't noticed that. It does indeed seem to be an issue with TigerVNC. I've opened an issue here:

https://github.com/TigerVNC/tigervnc/issues/1130

If you have time to dig a bit more then I'd appreciate it.

Hans, do you have any idea why this might be happening? It seems to be caused by your change to Tigervnc: https://github.com/TigerVNC/tigervnc/commit/712cf8673d6e57442f41636e44020f5e1839c7f8.

For now I have workarounded it by adding additional "-Log *:stderr:30" into the "xvnc@.service" file.

I think it was broken before Hans' change as well since there was a close(2) there.

I workarounded it for now and will update Tigervnc with a proper fix once we identify the real issue.

(In reply to Pierre Ossman from comment #11)
> I think it was broken before Hans' change as well since there was a close(2)
> there.

Right, mixing inetd usage and stderr for log output is not supported because some inetd versions will send not only anything written to stdout to the (tcp/ip) client but also anything written to stderr, see e.g.:
https://developer.ibm.com/technologies/linux/articles/au-spunix-inetd/

That is why the close(2) call was originally there; and my patch which you reference keeps the behavior of closing stderr. On top of that it now also opens /dev/null when closing stderr, since other code treats fd 2 (aka stderr) special and thus we don't want another subsequent open to return fd number 2, so we clobber that fd number now by opening /dev/null and tying it to fd 2 (which has the result of closing the resource that fd 2 was original referring to).

So since the systemd.service file is using the old inetd code paths in Xvnc and since those code paths are expected to not have a working stderr, everything seems to work as intended.

So short of adding support for systemd-style socket activation (where the stdin, stdout and stderr streams are not used for the socket) to Xvnc and using that instead of the classic inetd style socket-activation, there is nothing we can do here.

So it seems that the workaround is actually a pretty good solution here and we should just stick with it.

Ah, I see. Thank you.

What's required to do systemd-style socket activation? Is it something we can easily do?

And as an alternative, could we detect the systemd case and leave stderr alone in such cases? E.g. look at some environment variable, or can we check if stdout and stderr are the same socket?

(I also wonder if we should refuse to enable logging on stderr to avoid problems with those using a proper inetd, even if that breaks the workaround)

Please ignore my previous comment.

logs are now being printed to journal:

Dec 03 09:29:10 beaker-tigervnc-develop-495 Xvnc[62687]: vncext: VNC extension running!
Dec 03 09:29:10 beaker-tigervnc-develop-495 Xvnc[62687]: vncext: created VNC server for screen 0
Dec 03 09:29:10 beaker-tigervnc-develop-495 Xvnc[62687]: Connections: accepted: [::ffff:10.40.195.225]::43432
Dec 03 09:29:10 beaker-tigervnc-develop-495 Xvnc[62687]: vncext: added inetd sock
Dec 03 09:29:10 beaker-tigervnc-develop-495 Xvnc[62687]: SConnection: Client needs protocol version 3.8
Dec 03 09:29:10 beaker-tigervnc-develop-495 Xvnc[62687]: SConnection: Client requests security type None(1)
Dec 03 09:29:10 beaker-tigervnc-develop-495 Xvnc[62687]: VNCSConnST: Server default pixel format depth 24 (32bpp) little-endian rgb888
Dec 03 09:29:10 beaker-tigervnc-develop-495 Xvnc[62687]: VNCSConnST: Client pixel format depth 24 (32bpp) little-endian rgb888
Dec 03 09:29:13 beaker-tigervnc-develop-495 Xvnc[62687]: ComparingUpdateTracker: 0 pixels in / 0 pixels out
Dec 03 09:29:13 beaker-tigervnc-develop-495 Xvnc[62687]: ComparingUpdateTracker: (1:-nan ratio)

tigervnc-1.11.0-5.el8

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (Moderate: tigervnc security, bug fix, and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2021:1783