podman-remote: build: RUN causes [unwanted] debug output on client

[edsantiago]

Run podman server with debug enabled:

$ ./bin/podman --log-level=debug system service --timeout=0 $MYSOCK

Then, in another window, run a podman build using a Containerfile with a RUN:

$ mkdir a
$ echo 'FROM docker.io/library/alpine:latest' >a/Containerfile
$ echo 'RUN echo hi' >>a/Containerfile
$ ./bin/podman-remote --url $MYSOCK build a
[lots and lots of debug output from podman server]

[baude]

@edsantiago I do not see the debug that you see i guess... can you post an example.

$ sudo podman-remote --url unix:/run/podman/podman.sock build a
--> a24bb401329
a24bb4013296f61e89ba57005a7b3e52274d8edd3ae2077d04395f806b63d83e

FROM docker.io/library/alpine:latest
COMMIT
Successfully built a24bb4013296f61e89ba57005a7b3e52274d8edd3ae2077d04395f806b63d83e

[edsantiago]

@baude did you run the server with --log-level=debug?

[baude]

always do!

[edsantiago]

I left out this because I was filing so many bugs:

$ export MYSOCK=unix:/tmp/mypodmansock

Could that be it? I am still seeing it on current master

[edsantiago]

I can't find any way NOT to reproduce this, so I'll give a full recipe and will include logs.

In window 1:

$ ./bin/podman --log-level=debug system service --timeout=0 unix:/tmp/mypodmansock

Window 2:

$ cat a/Containerfile
FROM docker.io/library/alpine:latest
RUN echo hi
$ ./bin/podman-remote --url unix:/tmp/mypodmansock build a >6579-stdout 2>6579-stderr

All output, including debug messages, goes to 6579-stdout.txt, none to stderr.

One fact I had not noticed before is that the build (with or without --log-level=debug) results in an AVC:

type=AVC msg=audit(1592325652.218:113778): avc:  denied  { read write } for  pid=2547114 comm="sh" path="/dev/ptmx" dev="devtmpfs" ino=15713 scontext=system_u:system_r:container_t:s0:c51,c1014 tcontext=system_u:object_r:ptmx_t:s0 tclass=chr_file permissive=0

f32, kernel 5.6.7-300, container-selinux-2.135.0-1.fc32

[rhatdan]

If you put the machin in permissive mode, does it fix the issue?

[rhatdan]

I am getting DEBUG Also.

[edsantiago]

setenforce 0 makes no difference to the output seen on the client

[github-actions]

A friendly reminder that this issue had no activity for 30 days.

[rhatdan]

@edsantiago are you still seeing this problem?

[edsantiago]

Still seeing it on f32, master @ 17f9b80

[rhatdan]

@edsantiago a couple of months later still an issue?

[edsantiago]

Issue is still present, but I see no non-team watchers on the issue, so perhaps this isn't important to anyone but me.

I'm not going to be the one to close it, but I'll accept a CLOSED_NOBODYCARES from the team.

[rhatdan]

Well @jwhonce Is doing a rewrite of this section of code, so maybe it will be fixed in his next pass.

[edsantiago]

FWIW, issue still present after #7452

[jwhonce]

@edsantiago Thanks for attaching the output. That is coming up from buildah on stderr. At the podman/libpod layer I can either ignore stderr or display it. I cannot filter because of partial writes coming out of buildah.

[rhatdan]

@edsantiago @jwhonce Is this still an issue?

[edsantiago]

Yes, I still consider this an issue. It violates POLA for a debug flag on the server to cause debug output on the client. But as I mentioned in my September 10 comment, I will accept CLOSED_NOBODYCARES; I'm just not willing to be the one closing it.

[baude]

@umohnani8 do you think your work on fixing the stderr/stdout munging will fix this? or completely unrelated?

[umohnani8]

@baude no that doesn't target the debug level logs. Do we want those logs to output to stderr instead of stdout? I can look into fixing that if that is what we want.

[github-actions]

A friendly reminder that this issue had no activity for 30 days.

[rhatdan]

@umohnani8 have you had a chance to look at this?

[umohnani8]

Yeah, this was not related to the issue we had filed in buildah containers/buildah#2423. Buildah writes all debug and extra output to stderr. Maybe something to do with remote here?

[github-actions]

A friendly reminder that this issue had no activity for 30 days.

[github-actions]

A friendly reminder that this issue had no activity for 30 days.

[rhatdan]

I just tried this experiment and saw no output. Reopen if you have a new repeater.

[edsantiago]

Problem still exists on my end, but it looks like I'm the only one who finds this objectionable. I'll leave it closed until someone in the community comments.

[rhatdan]

Well we are having major discussions on this on another Issue or PR, between @nalind and @jwhonce on the best way to handle logrus messages in podman-remote build.