tstack / lnav

Log file navigator
http://lnav.org
BSD 2-Clause "Simplified" License
7.85k stars 313 forks source link

docker:// not working (well) - hangs, does not update #1183

Open shoffmeister opened 1 year ago

shoffmeister commented 1 year ago

lnav version

Downloaded musl binary from CI (https://github.com/tstack/lnav/actions/workflows/bins.yml) at https://github.com/tstack/lnav/commit/eda33d696da33416aae09cb1824ee88dffafbd58 (a couple of minutes ago)

Describe the bug

lnav hangs dead upon starting with a docker:// URL. Ctrl+C "unlocks" something, but then no further updates take place.

To Reproduce

Terminal 1:

docker run -it --rm --name lnav-target bash bash -c 'while true; do sleep 1; echo $(date --utc); done'

Terminal 2:

lnav docker://lnav-target

//exp: lnav immediately shows the output from docker (stdout) //act: lnav hangs dead

Press Ctrl+C - and lnav updates log content, but only once. It is possible to navigate in those logs.

Press Ctrl+C again - and lnav terminates

My eventual goal is to have the equivalent of

docker run -it --rm --name lnav-target-1 bash bash -c 'while true; do sleep 1; echo "c1: $(date --utc)"; done'
docker run -it --rm --name lnav-target-2 bash bash -c 'while true; do sleep 1; echo "c2: $(date --utc)"; done'

and

lnav docker://lnav-target-1 docker://lnav-target-2

working. Right now, that seems to offer additional challenges.

System is Fedora Linux 38 (inside a virtual machine). With the bare metal file logs (running lnav), everything works fine.

shoffmeister commented 1 year ago

I get the same behaviour when running

lnav -e 'docker logs -f lnav-target'
❯ docker --version
Docker version 24.0.5, build ced0996
shoffmeister commented 1 year ago

The following strategy enables "following" docker logs, but is less convenient ... and seems to be very prone to lnav opening / closing files (the FIFO pipe)?

mkfifo lnav-target
docker logs -f lnav-target >> lnav-target
lnav lnav-target
tstack commented 1 year ago

Thanks for trying it out and giving a heads up! I had made a change after the docker/url work that caused the problem. I've pushed a quick fix to get it going again. Need to think a bit to figure out how to improve the behavior a bit more.

shoffmeister commented 1 year ago

Many thanks for the fantastically fast fix!

Current HEAD works very well for

docker run -it --rm --name lnav-target-1 bash bash -c 'while true; do sleep 1; echo "$(date -Ins) INFO c1"; done'
docker run -it --rm --name lnav-target-2 bash bash -c 'while true; do sleep 1; echo "$(date -Ins) INFO c2"; done'

lnav docker://lnav-target-1 docker://lnav-target-2

I can now look into doing fancier things: I like setting up local notebook infrastructure with docker compose (podman-compose) stacks, without building up a resource-heavy ELK stack. lnav would probably simplify interacting with this quite a bit.

tstack commented 1 year ago

@shoffmeister Should there be a docker-compose:// URL that loads the logs for the services in the local docker-compose.yml file?

shoffmeister commented 1 year ago

@tstack while docker-compose:// sounds like a logical extension, I am unclear about what "local docker-compose.yml file" would mean:

My experiments tend to involve some however arbitrarily named baseline docker-compose.yaml often enriched with addons, launch immediately or later on: docker compose -f d1.yml -f d2.yml -f d3.yml

One directory right now has

❯ ls *.y*
docker-compose.addon.grafana.yaml         docker-compose.addon.splunk.yaml
docker-compose.addon.opentelementry.yaml  docker-compose.yml

and that's more the rule than the exception.

I just successfully tried

containers=($(docker container ls --all --format '{{.Names}}')); ./lnav "${containers[@]/#/docker://}"
containers=($(docker ps --format '{{.Names}}')); ./lnav "${containers[@]/#/docker://}"

While this is not what docker-compose:// would do, practically it may be very close? This makes me suspect that documenting approaches cookbook-style to conveniently provisioning a list of log source targets could work well?

Not implementing docker-compose:// would also allow leaving the identity crisis of podman-compose unaddressed ;)

And, after all that, someone will come up with a request to "hey, lnav all Deployments over all namespaces of that k3s cluster". I wouldn't open the door for that.


version: "2"

services:
  s1:
    image: bash
    command: bash -c 'while true; do sleep 1; echo "$(date -Ins) INFO s1"; done'
  s2:
    image: bash
    command: bash -c 'while true; do sleep 1; echo "$(date -Ins) INFO s2"; done'
  s3:
    image: bash
    command: bash -c 'for i in {1..5}; do sleep 1; echo "$(date -Ins) WARN s3"; done; exit 99'
tstack commented 1 year ago

I've pushed a change that adds some initial support for docker compose. If you use compose as the hostname with the path to the configuration file, it will launch docker compose logs for each service specified in the config file. For example, if there is a compose.yaml file in the current directory, you can do:

lnav docker://compose/compose.yaml

That will tail all of the service logs separately, so the LOG (or TEXT) view will show the messages associated with a particular container.

Note that the docker compose logs processes don't seem to exit when lnav exits. I think this is a docker issue.

I don't really use docker much, so I'm not sure how useful this is. Let me know if you have time to try it out and if there are gaps.

Thanks

shoffmeister commented 1 year ago

@tstack Interesting! I gave the "compose" support a whirl with my local stacks and noticed a few things:

a) does not accept "---" at the top of a YAML document - but docker compose does; presence of --- yields

✘ error: failed to parse YAML content                                                                                                                                                                           │
 reason: check failed: !m_tree->is_stream(id)         

Generally, IIRC, docker supports multi-document YAML files, i.e. more than one YAML document in a single file. --- is the separator between those documents. See https://yaml.org/spec/1.2.2/ - "2.2. Structures"

b) "compose" implementation is too general; in https://github.com/tstack/lnav/commit/38e5fa594553392643869bcde7d70759623deff3#diff-8b93f0d06f87b27b049e1357526684516a8ee4382042b4051916ae155f132918R18 very generic support for the "compose" feature is added. This implementation assumes that on a user's system the following works

Alas ...

docker-compose and podman-compose are separate installations, so docker being available does not guarantee the presence of the -composes.

All this applies, IIRC, to both Linux and Windows.

It's a mess.

Having tried compose support in lnav, I recognize this as quite user-friendly. I am torn. :man_shrugging:

c) compose support is not cumulative, does not aggregate, i.e. lnav docker://compose/docker-compose.yml docker://compose/docker-compose.addon.grafana.yaml only shows the content of the second stack. This is in contrast to lnav docker://zookeeper docker://grafana which works as expected. docker compose -f ... for the respective compose files does the expected thing, so it appears to be an issue in the aggregation of the composes in lnav.


Repro yaml for item a)

---
version: "2"

services:
  s1:
    image: bash
    command: bash -c 'while true; do sleep 1; echo "$(date -Ins) INFO s1"; done'
  s2:
    image: bash
    command: bash -c 'while true; do sleep 1; echo "$(date -Ins) INFO s2"; done'
  s3:
    image: bash
    command: bash -c 'for i in {1..5}; do sleep 1; echo "$(date -Ins) WARN s3"; done; exit 99'
tstack commented 1 year ago

a) does not accept "---" at the top of a YAML document - but docker compose does; presence of --- yields

I've pushed a change that tries to address this.

c) compose support is not cumulative

Hmm, I'm not able to reproduce this, but I'm not sure I'm doing the right thing either. Is the docker://compose/docker-compose.addon.grafana.yaml just a regular compose file? I can pass two different compose YAML config files and all of the service logs are loaded up.

Thanks for the detailed response!

piotr-dobrogost commented 1 year ago

a) does not accept "---" at the top of a YAML document - but docker compose does (…)

You mean the support added only 4 days ago in version v2.21.0 (Support for multi-document YAML files (https://github.com/compose-spec/compose-go/pull/451))

shoffmeister commented 1 year ago

Hmm, I have habitually putting --- at the top of docker-compose.yaml for many years- and it has been working well?

Now, true multi-document support - yeah, my memory is ... blurred? ... from all those stacks. Historically, I have been assembling these through multiple --file specs, or through some addon pattern which tack onto existing volumes / networks. All that is for quick and resource-friendly local LEGO fun with containers.

shoffmeister commented 1 year ago

@tstack Sorry for the long delay in getting back on the "compose not cumulative" issue that I reported above!

It would seem as if there is a different problem: lnav simply errors out on the first docker compose file with

✘ error: unknown command - <NULL>  

And it is really the content of the compose file which is responsible: debug.zip

To reproduce, simply run the latest CI build with lnav docker://compose/debug.yaml

Note that the file is already trimmed down; the original size is 6 KB.

shoffmeister commented 1 year ago

FWIW, I am on a "modern" Docker installation; because of that, I do not have docker-compose but only docker compose.

To get lnav to work with this setup, having a simple script like the one below on the PATH is sufficient:

f="docker-compose"; touch $f; chmod u+x $f; cat > $f <<'EOF'
#!/usr/bin/env bash

docker compose "${@}"
EOF