Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Support --logfile CLI option for all subcommands including login, rather than only build #20251

Closed
sanmai-NL opened this issue Oct 4, 2023 · 31 comments
Labels
kind/feature Categorizes issue or PR as related to a new feature. locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments.

Comments

@sanmai-NL
Copy link
Contributor

sanmai-NL commented Oct 4, 2023

Feature request description

See title.

Suggest potential solution

See title. My hope is that the logging logic can be factored out and reused for all of podman. Even if perhaps, some subcommands tend to emit fewer log items.

Have you considered any alternatives?

See title.

An alternative is to manually save stderr or stdout, depending on the type of log file (human vs. machine readable). But it makes no sense for one subcommand to have the option and the other not to.

Additional context

None.

@sanmai-NL sanmai-NL added the kind/feature Categorizes issue or PR as related to a new feature. label Oct 4, 2023
@baude
Copy link
Member

baude commented Oct 4, 2023

a title is not typically complete enough of a feature request. i would recommend fixing this up to indicate why you want this, how it would be used, and why others would.

@sanmai-NL
Copy link
Contributor Author

a title is not typically complete enough of a feature request. i would recommend fixing this up to indicate why you want this, how it would be used, and why others would.

In understand your concern. But have you read my post? Your questions are answered there.

I can't speak for others.

The motivation is the same as for the existing --logfile option, in combination with the principle of generic feature parity between subcommands.

Copy link

github-actions bot commented Nov 4, 2023

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

@sanmai-NL
Copy link
Contributor Author

Not stale.

@rhatdan
Copy link
Member

rhatdan commented Nov 4, 2023

Interested in opening a PR to make this change?

@sanmai-NL
Copy link
Contributor Author

Yes, but this is beyond my Go proficiency (which is practically zero now). If some pointers can be left about the main modules to study, and the current logging architecture, it would make it more doable for me as well as others.

@rhatdan
Copy link
Member

rhatdan commented Nov 6, 2023

$ podman --log-level=debug login
INFO[0000] podman filtering at log level debug          
DEBU[0000] Called login.PersistentPreRunE(podman --log-level=debug login) 
DEBU[0000] Using conmon: "/usr/bin/conmon"              
DEBU[0000] Initializing boltdb state at /home/dwalsh/.local/share/containers/storage/libpod/bolt_state.db 
DEBU[0000] Using graph driver overlay                   
DEBU[0000] Using graph root /home/dwalsh/.local/share/containers/storage 
DEBU[0000] Using run root /run/user/3267/containers     
DEBU[0000] Using static dir /home/dwalsh/.local/share/containers/storage/libpod 
DEBU[0000] Using tmp dir /run/user/3267/libpod/tmp      
DEBU[0000] Using volume path /home/dwalsh/.local/share/containers/storage/volumes 
DEBU[0000] Using transient store: false                 
DEBU[0000] [graphdriver] trying provided driver "overlay" 
DEBU[0000] Cached value indicated that overlay is supported 
DEBU[0000] Cached value indicated that overlay is supported 
DEBU[0000] Cached value indicated that metacopy is not being used 
DEBU[0000] Cached value indicated that native-diff is usable 
DEBU[0000] backingFs=xfs, projectQuotaSupported=false, useNativeDiff=true, usingMetacopy=false 
DEBU[0000] Initializing event backend journald          
DEBU[0000] Configured OCI runtime runj initialization failed: no valid executable found for OCI runtime runj: invalid argument 
DEBU[0000] Configured OCI runtime runsc initialization failed: no valid executable found for OCI runtime runsc: invalid argument 
DEBU[0000] Configured OCI runtime ocijail initialization failed: no valid executable found for OCI runtime ocijail: invalid argument 
DEBU[0000] Configured OCI runtime kata initialization failed: no valid executable found for OCI runtime kata: invalid argument 
DEBU[0000] Configured OCI runtime youki initialization failed: no valid executable found for OCI runtime youki: invalid argument 
DEBU[0000] Using OCI runtime "/usr/bin/crun"            
INFO[0000] Setting parallel job count to 37             
DEBU[0000] Loading registries configuration "/etc/containers/registries.conf" 
DEBU[0000] Loading registries configuration "/etc/containers/registries.conf.d/000-shortnames.conf" 
DEBU[0000] registry not specified, default to the first registry "registry.fedoraproject.org" from registries.conf 
DEBU[0000] No credentials matching registry.fedoraproject.org found in /run/user/3267/containers/auth.json 
DEBU[0000] No credentials matching registry.fedoraproject.org found in /home/dwalsh/.config/containers/auth.json 
DEBU[0000] No credentials matching registry.fedoraproject.org found in /home/dwalsh/.docker/config.json 
DEBU[0000] No credentials matching registry.fedoraproject.org found in /home/dwalsh/.dockercfg 
DEBU[0000] No credentials for registry.fedoraproject.org found 
Username: 

Do you need more then this?

@rhatdan
Copy link
Member

rhatdan commented Nov 6, 2023

$ podman --log-level=debug login 2>/tmp/debug
Username: ^c
$ cat /tmp/debug 
time="2023-11-06T09:55:14-06:00" level=info msg="podman filtering at log level debug"
time="2023-11-06T09:55:14-06:00" level=debug msg="Called login.PersistentPreRunE(podman --log-level=debug login)"
time="2023-11-06T09:55:14-06:00" level=debug msg="Using conmon: \"/usr/bin/conmon\""
time="2023-11-06T09:55:14-06:00" level=debug msg="Initializing boltdb state at /home/dwalsh/.local/share/containers/storage/libpod/bolt_state.db"
time="2023-11-06T09:55:14-06:00" level=debug msg="Using graph driver overlay"
time="2023-11-06T09:55:14-06:00" level=debug msg="Using graph root /home/dwalsh/.local/share/containers/storage"
time="2023-11-06T09:55:14-06:00" level=debug msg="Using run root /run/user/3267/containers"
time="2023-11-06T09:55:14-06:00" level=debug msg="Using static dir /home/dwalsh/.local/share/containers/storage/libpod"
time="2023-11-06T09:55:14-06:00" level=debug msg="Using tmp dir /run/user/3267/libpod/tmp"
time="2023-11-06T09:55:14-06:00" level=debug msg="Using volume path /home/dwalsh/.local/share/containers/storage/volumes"
time="2023-11-06T09:55:14-06:00" level=debug msg="Using transient store: false"
time="2023-11-06T09:55:14-06:00" level=debug msg="[graphdriver] trying provided driver \"overlay\""
time="2023-11-06T09:55:14-06:00" level=debug msg="Cached value indicated that overlay is supported"
time="2023-11-06T09:55:14-06:00" level=debug msg="Cached value indicated that overlay is supported"
time="2023-11-06T09:55:14-06:00" level=debug msg="Cached value indicated that metacopy is not being used"
time="2023-11-06T09:55:14-06:00" level=debug msg="Cached value indicated that native-diff is usable"
time="2023-11-06T09:55:14-06:00" level=debug msg="backingFs=xfs, projectQuotaSupported=false, useNativeDiff=true, usingMetacopy=false"
time="2023-11-06T09:55:14-06:00" level=debug msg="Initializing event backend journald"
time="2023-11-06T09:55:14-06:00" level=debug msg="Configured OCI runtime kata initialization failed: no valid executable found for OCI runtime kata: invalid argument"
time="2023-11-06T09:55:14-06:00" level=debug msg="Configured OCI runtime youki initialization failed: no valid executable found for OCI runtime youki: invalid argument"
time="2023-11-06T09:55:14-06:00" level=debug msg="Configured OCI runtime runj initialization failed: no valid executable found for OCI runtime runj: invalid argument"
time="2023-11-06T09:55:14-06:00" level=debug msg="Configured OCI runtime runsc initialization failed: no valid executable found for OCI runtime runsc: invalid argument"
time="2023-11-06T09:55:14-06:00" level=debug msg="Configured OCI runtime ocijail initialization failed: no valid executable found for OCI runtime ocijail: invalid argument"
time="2023-11-06T09:55:14-06:00" level=debug msg="Using OCI runtime \"/usr/bin/crun\""
time="2023-11-06T09:55:14-06:00" level=info msg="Setting parallel job count to 37"
time="2023-11-06T09:55:14-06:00" level=debug msg="Loading registries configuration \"/etc/containers/registries.conf\""
time="2023-11-06T09:55:14-06:00" level=debug msg="Loading registries configuration \"/etc/containers/registries.conf.d/000-shortnames.conf\""
time="2023-11-06T09:55:14-06:00" level=debug msg="registry not specified, default to the first registry \"registry.fedoraproject.org\" from registries.conf"
time="2023-11-06T09:55:14-06:00" level=debug msg="No credentials matching registry.fedoraproject.org found in /run/user/3267/containers/auth.json"
time="2023-11-06T09:55:14-06:00" level=debug msg="No credentials matching registry.fedoraproject.org found in /home/dwalsh/.config/containers/auth.json"
time="2023-11-06T09:55:14-06:00" level=debug msg="No credentials matching registry.fedoraproject.org found in /home/dwalsh/.docker/config.json"
time="2023-11-06T09:55:14-06:00" level=debug msg="No credentials matching registry.fedoraproject.org found in /home/dwalsh/.dockercfg"
time="2023-11-06T09:55:14-06:00" level=debug msg="No credentials for registry.fedoraproject.org found"
time="2023-11-06T09:55:16-06:00" level=info msg="Received shutdown signal \"interrupt\", terminating!" PID=1698901
time="2023-11-06T09:55:16-06:00" level=info msg="Invoking shutdown handler \"libpod\"" PID=1698901

@sanmai-NL
Copy link
Contributor Author

sanmai-NL commented Nov 6, 2023

I develop a few wrappers around Podman subcommands, and it occurred to me that some subcommands don't support the --logfile option whereas others do. Of course, one can find out which subcommands don't, like login, and then write special case code for that.

@rhatdan
Copy link
Member

rhatdan commented Nov 6, 2023

Well the only command that supports this is podman build, which is actually a vendor of buildah, which includes the option.

@sanmai-NL
Copy link
Contributor Author

sanmai-NL commented Nov 7, 2023

That's an interesting historical background/context!

I use the --logfile option in an effort to create logs of every Podman operation in CI/CD pipelines, that include all info you need to debug faults. It's nice from a maintainability point of view if I can control logging of all podman invocations (heck, even do something like configuring logging centrally, or otherwise to alias podman to podman --logfile).

@rhatdan
Copy link
Member

rhatdan commented Nov 8, 2023

@edsantiago @Luap99 WDYT?

@edsantiago
Copy link
Member

I'm sorry. I can't see any possible justification for this. I even consider podman build --logfile to be a mistake. It doesn't seem to do anything that can't be solved using redirection. It feels like a throwback to VMS.

@sanmai-NL you were asked, within minutes of opening this issue, to justify your request. You declined. I will ask again: please justify your request, with full examples of how you see this being used and what you see this solving that podman ... >>logfile does not solve.

@rhatdan
Copy link
Member

rhatdan commented Nov 8, 2023

I would be fine with hiding podman build --logfile` and removing documentation.

It seems like it might have been added for podman build on multi-streams. @flouthoc Do you recall why this flag was added?

@edsantiago
Copy link
Member

--logfile dates back to June 2018, containers/buildah#754

It does look useful in this combination:

If --logfile and --platform is specified following flag allows end-users to split log file for each
platform into different files with naming convention as `${logfile}_${platform-os}_${platform-arch}`.

However, my limited imagination fails to find a case where this could apply to any other podman option.

@flouthoc
Copy link
Collaborator

flouthoc commented Nov 9, 2023

@edsantiago Is correct, buildah even implemented --logsplit with --logfile to record logs of muti-arch builds. I think its useful for builds. Should we really hide it ? containers/buildah#4034

@Luap99
Copy link
Member

Luap99 commented Nov 9, 2023

Note we already have the global --out option for stdout redirection. Adding something for stderr redirection is thus not so far off.

I tend to agree with @edsantiago that io redirection is something callers should do, adding options for this to each and every application seems wrong in general. However given there is precedent for stdout I would not object adding a new option for stderr.

@flouthoc
Copy link
Collaborator

flouthoc commented Nov 9, 2023

@Luap99 For buildah's multi-arch builds --out is not enough since it mixes the logs of different builds ( as multiple builds are running concurrently ) given that I think buildah build has a unique use-case, can't think this for other commands and I agree that --out should be used wherever possible.

@rhatdan
Copy link
Member

rhatdan commented Nov 9, 2023

I would vote no, just rely on the shell.

@sanmai-NL
Copy link
Contributor Author

sanmai-NL commented Nov 14, 2023

As a user, here's my perspective again.

  1. The --out parameter is not discoverable enough for me. The functional difference between --logfile and --out isn't documented well enough for me either.
  2. The --logspit parameter is also not discoverable enough for me. It‘s listed in the man page, but not in the CLI --help text (Podman 4.7.2). This could be due to remote podman trying to be helpful and filtering out parameters that are not available, but this adds to confusion about the maximal feature set of the CLI tool.
  3. I wonder whether writes to stdout and stderr are so hygienically separated in the Podman source code base, as in, with clear semantics and to the extent that log collection can be left to the caller. For example, a common design choice is: stdout only for machine-readable output, stderr for other output. But now, for example, podman login dumps a whole lot of text to stderr, and to stdout 'Login Succeed'. I don't see the logic in that. Which means my wrapper tools need to diligently collect both stdout and stderr of all podman invocations.
  4. If proper structured logging is used, it should be well possible for the caller to discern log entries for container image builds for --arch x from --arch y without --logsplit.
  5. I don‘t need the --logfile functionality, in light of the alternatives that I now discovered, if you address the previous points.

@sanmai-NL
Copy link
Contributor Author

sanmai-NL commented Nov 14, 2023

I'm sorry. I can't see any possible justification for this. I even consider podman build --logfile to be a mistake. It doesn't seem to do anything that can't be solved using redirection. It feels like a throwback to VMS.

@sanmai-NL you were asked, within minutes of opening this issue, to justify your request. You declined. I will ask again: please justify your request, with full examples of how you see this being used and what you see this solving that podman ... >>logfile does not solve.

Hi @edsantiago,

Please note that I didn't request adding --logfile for all subcommands no matter what, just that as a user I expect feature parity between subcommands. If this feature doesn't add value in hindsight, deprecating it is an option. Your argumentation in favor of a work-around can be applied to any feature, and isn't sound reasoning. Can you justify why you develop podman build and what you see it solving that buildah can't solve? See, this makes no sense and is little forthcoming to a user.

I have justified the feature request in the OP. If you miss something, please point out what. I think the additional context you want is in #20251 (comment), by the way.

@sanmai-NL
Copy link
Contributor Author

sanmai-NL commented Nov 14, 2023

In addition to #20251 (comment), I find that even when capturing stdout with --out, stderr manually and using --logfile all at the same time, some logging output is still written to the terminal. (When using the Podman container image on a Linux VM.)

time="2023-11-14T11:17:53Z" level=info msg="podman filtering at log level debug"
time="2023-11-14T11:17:53Z" level=debug msg="Called build.PersistentPreRunE(podman --log-level debug buildx build --arch=amd64 --os=linux --file=k8s/Containerfile --logfile=podman-build.builder.log --tag builder:latest --target builder .)"
time="2023-11-14T11:17:53Z" level=debug msg="Using conmon: \"/usr/bin/conmon\""
time="2023-11-14T11:17:53Z" level=debug msg="Initializing boltdb state at /var/lib/containers/storage/libpod/bolt_state.db"
time="2023-11-14T11:17:53Z" level=debug msg="Using graph driver overlay"
time="2023-11-14T11:17:53Z" level=debug msg="Using graph root /var/lib/containers/storage"
time="2023-11-14T11:17:53Z" level=debug msg="Using run root /run/containers/storage"
time="2023-11-14T11:17:53Z" level=debug msg="Using static dir /var/lib/containers/storage/libpod"
time="2023-11-14T11:17:53Z" level=debug msg="Using tmp dir /run/libpod"
time="2023-11-14T11:17:53Z" level=debug msg="Using volume path /var/lib/containers/storage/volumes"
time="2023-11-14T11:17:53Z" level=debug msg="Using transient store: false"
time="2023-11-14T11:17:53Z" level=debug msg="[graphdriver] trying provided driver \"overlay\""
time="2023-11-14T11:17:53Z" level=debug msg="overlay: imagestore=/var/lib/shared"
time="2023-11-14T11:17:53Z" level=debug msg="overlay: mount_program=/usr/bin/fuse-overlayfs"
time="2023-11-14T11:17:53Z" level=debug msg="backingFs=extfs, projectQuotaSupported=false, useNativeDiff=false, usingMetacopy=false"
time="2023-11-14T11:17:53Z" level=debug msg="Initializing event backend file"
time="2023-11-14T11:17:53Z" level=debug msg="Configured OCI runtime kata initialization failed: no valid executable found for OCI runtime kata: invalid argument"
time="2023-11-14T11:17:53Z" level=debug msg="Configured OCI runtime runc initialization failed: no valid executable found for OCI runtime runc: invalid argument"
time="2023-11-14T11:17:53Z" level=debug msg="Configured OCI runtime runj initialization failed: no valid executable found for OCI runtime runj: invalid argument"
time="2023-11-14T11:17:53Z" level=debug msg="Configured OCI runtime runsc initialization failed: no valid executable found for OCI runtime runsc: invalid argument"
time="2023-11-14T11:17:53Z" level=debug msg="Configured OCI runtime youki initialization failed: no valid executable found for OCI runtime youki: invalid argument"
time="2023-11-14T11:17:53Z" level=debug msg="Configured OCI runtime krun initialization failed: no valid executable found for OCI runtime krun: invalid argument"
time="2023-11-14T11:17:53Z" level=debug msg="Configured OCI runtime ocijail initialization failed: no valid executable found for OCI runtime ocijail: invalid argument"
time="2023-11-14T11:17:53Z" level=debug msg="Configured OCI runtime crun-wasm initialization failed: no valid executable found for OCI runtime crun-wasm: invalid argument"
time="2023-11-14T11:17:53Z" level=debug msg="Using OCI runtime \"/usr/bin/crun\""
time="2023-11-14T11:17:53Z" level=info msg="Setting parallel job count to 13"

@edsantiago
Copy link
Member

Thank you, but we still seem to be stuck. You believe you have justified your request; I believe you have not. Could you please type two examples, fully spelled out, showing exact commands, exactly as they would be typed or written in a script, demonstrating this feature you're requesting? And then can you explain exactly how this would differ from command-line redirection?

@sanmai-NL
Copy link
Contributor Author

@edsantiago I observe that you're not responding to the specific content in comments, and come up with a requirement for me to re-explain something in a certain manner. Your colleagues seem to get the point and discuss various arguments around this issue. Again, you're somehow surmising that I accept nothing but --logfile being supported across subcommands, while I merely argue in favor of that in my OP and subsequent post, yet arguments can be exchanged about it, like your colleagues do, and an alternative conclusion could be to deprecate --logfile.

podman build --logfile=podman-build-...log ...
podman login 2>podman-login-...log ...

The preceding lines show the disparity between subcommands. This made no sense to me. Logging stderr to a file seems like a utility one would implement for all of Podman, and a convenience for users applicable to all of Podman, rather than just some subcommands. I proposed to support, for instance, this:

podman build --logfile=podman-build-...log ...

This difference in CLI interface gets more problematic when developing wrapper software.

if __name__ == "__main__":
    path_file_log = Path(
        sanitize_filename(
            f"podman-build.{timestamp}.log",
            replacement_text="--",
        ),
    )
    run(
           [  # noqa: S603
               "podman",
               "--log-level=debug", 
               f"--logfile={path_file_log}"
           ],
    )
if __name__ == "__main__":
    path_file_log = Path(
        sanitize_filename(
            f"podman-login.{timestamp}.log",
            replacement_text="--",
        ),
    )
    with path_file_log_stderr_push.open(
        mode="x",
        encoding="utf-8",
        ) as file_log_stderr_push:
         run(
                [  # noqa: S603
                    "podman",
                    "--log-level=debug",
                ],
                stderr=file_log_stderr_push,
         )

Now what if I want to implement a class that can run Podman subcommands with a few generic parameters already set, like logging? Then I will have to special case for various subcommands, and find out which ones do support logging to a file as a convenience feature and which don't. And without the convenience functionality in the first place, I'll have to manage logging (files) as a caller.

Later it turned out there's an --out parameter that helps with this. Nice. There do appear to be a few kinks in the functionality, as I described in my previous few posts. But nonetheless, this is a nice improvement.

Now, what of this information you didn't get from the previous posts?

@edsantiago
Copy link
Member

Thank you for your examples. I think they actually demonstrate the converse of what you're requesting: the correct solution is to use Python's (or any language's) facilities for capturing stdout/stderr. That's how redirection has worked in UNIX since the beginning. Tacking on (and maintaining) an unnecessary option is a burden. Would you want ls --logfile? echo --logfile?

@sanmai-NL
Copy link
Contributor Author

sanmai-NL commented Nov 17, 2023

I think we're moving into highly subjective territory now.

Managing logfiles is something many tools offer to take on. Why, if you think's out of scope in general? The pre-existence of --logfile in podman build and your colleagues' discussion suggests some value was seen in it, still. Data written to stderr or stdout may or may not be a (structured) log entry. The caller may use a shell in which separating stderr from stdout is impractical.

Without addressing my points (e.g., around documentation), simply saying the caller should capture stderr and/or stdout does not fully address the issue I raised. I asked the fundamental question: why does this option exist, for some subcommand but not for others?

@rhatdan
Copy link
Member

rhatdan commented Nov 18, 2023

I agree with Ed, we will not be adding additional options.

@rhatdan rhatdan closed this as completed Nov 18, 2023
@rhatdan
Copy link
Member

rhatdan commented Nov 18, 2023

We have answered the reason the buildah one exists. If the buildah team do not think it is necessary then they can deprecate it.

@sanmai-NL
Copy link
Contributor Author

@rhatdan I hope I won't have to file each and every point* separately now, for you and your team to actually capture the user input.

#20251 (comment) *

@sanmai-NL
Copy link
Contributor Author

sanmai-NL commented Nov 20, 2023

We have answered the reason the buildah one exists. If the buildah team do not think it is necessary then they can deprecate it.

I think you're taking a shortcut out of a discussion you don't want to continue. There is no argumentation on what makes the other subcommands so different. It's always easier to ignore comments.

@rhatdan
Copy link
Member

rhatdan commented Nov 20, 2023

You are welcome to continue your conversation, but know we don't intend to implement it.

@github-actions github-actions bot added the locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments. label Feb 19, 2024
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Feb 19, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
kind/feature Categorizes issue or PR as related to a new feature. locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments.
Projects
None yet
Development

No branches or pull requests

6 participants