Loki: if loki is not reachable and loki-docker-driver is activated, containers apps stops and cannot be stopped/killed

[badsmoke]

Describe the bug
we have installed the loki-docker-driver on all our devices.
The loki server on an extra server, if the loki-server is updated/restarted or just not reachable then after a short time all containers get stuck (docker logs does not update anymore).
If the loki-server is not reachable, the containers can neither be stopped/kill nor restarted.

To Reproduce
Steps to reproduce the behavior:

1. start loki server (server)
2. install loki-docker-driver on another system (can also be tested on one and the same system) (client)
   2.1. /etc/docker/daemon.json { "live-restore": true, "log-driver": "loki", "log-opts": { "loki-url": "http://loki:3100/api/prom/push", "mode": "non-blocking", "loki-batch-size": "400", "max-size": "1g" } }
3. docker run --rm --name der-container -d debian /bin/sh -c "while true; do date >> /tmp/ts ; seq 0 1000000; sleep 1 ; done"(client)
4. docker exec -it der-container tail -f /tmp/ts
   shows every second the time (client)
5. docker logs -f der-container show numbers from 0-1000000 (client)
6. stop loki server (server)
7. you will see that the outputs on the system stop with the loci-driver and that you cannot stop the container (client)
8. docker stop der-container (client)

Expected behavior
A clear and concise description of what you expected to happen.
I would like all containers to continue to run as desired even if the loci is not accessible.
That man container can start/stop even if loki is not reachable

Environment:

• Infrastructure: [bare-metal, laptop, VMs]
• Deployment tool: [docker-compose]

Screenshots, Promtail config, or terminal output
loki-docker-driver version: loki-docker-driver:master-616771a (from then on the driver option "non-blocking" is supported)
loki server: 1.5.0

I am very grateful for any help, this problem has caused our whole system to collapse

[stale[bot]]

This issue has been automatically marked as stale because it has not had any activity in the past 30 days. It will be closed in 7 days if no further activity occurs. Thank you for your contributions.

[badsmoke]

:-(

[rkno82]

This issue is being closed without any comment/ feedback?

For me/ us this is a major issue/ blocker.

@owen-d Can you please comment? Thank you!

[ondrejmo]

2017 fixed the same problem for me

[rndmh3ro]

2017 fixed the same problem for me

Do you mean setting the non-blocking mode?
The OP stated that they set the mode to non-blocking but it still does not work. I'll have to try it tomorrow.

[rndmh3ro]

I could reproduce the problem:

root@loki # docker run -d --log-driver=loki     --log-opt loki-url="http://172.29.95.195:3101/loki/api/v1/push"     --log-opt loki-retries=5     --log-opt loki-batch-size=400 --log-opt mode=non-blocking  --name der-container -d debian /bin/sh -c "while true; do date >> /tmp/ts ; seq 0 1000000; sleep 1 ; done"```

Running loki and the above client-container, then stopping loki, the client-container fails:
error from daemon in stream: Error grabbing logs: error decoding log message: net/http: request canceled (Client.Timeout exceeded while reading body)

[ondrejmo]

2017 fixed the same problem for me

Do you mean setting the non-blocking mode?
The OP stated that they set the mode to non-blocking but it still does not work. I'll have to try it tomorrow.

Yeah I meant the non-blocking mode, I haven't noticed it in the original issue, sorry.

[rkno82]

No response? 😢

[Pandry]

Hi,
We are testing Loki for our architecture, and I encountered this issue too

I found out that the time needed to stop a container (any container) has "penalty" between 5 and 15 minutes when loki is the logging driver and the destination server (either loki or promtail) is unreachable.
In our testing architecture, we have the docker log driver that pushes the logs to the promtail container, and promtail that pushes the logs to the loki server (I tought (promtail cached and so) it could have been a good idea)

+-----------------------+   +--------------------+
|    Virtual Machine 01 |   | Virtual Machine 02 |
|                       |   |                    |
|   +------+--------+   |   |                    |
|   |Loki  | Docker |   |   |                    |
|   |DRIVER|        |   |   |                    |
|   +-+---++        |   |   |                    |
|   | ^   |         |   |   | +--------+         |
|   | | +-v------+  |   |   | | Loki   |         |
|   | | |Promtail+----------->+ Server |         |
|   | | +--------+  |   |   | |        |         |
|   | |             |   |   | +--------+         |
|   | +-------+     |   |   |                    |
|   | | NGINX |     |   |   |                    |
|   | +-------+     |   |   |                    |
|   +---------------+   |   |                    |
|                       |   |                    |
+-----------------------+   +--------------------+

At the moment we are trying with the mode: non-blocking mode, and, other than slowing down the stop of the promtail container itself, it seems to be ok with the other containers but it's not working anyway.

Is there any viable fix available at the moment?

[kavirajk]

I'm investigating!

you can even reproduce by directly start any container with loki logger and some unreachable loki-url,

1. with local log driver

docker run --log-driver local --log-opt max-size=10m alpine ping 127.0.0.1

1. with loki log driver

docker run --log-driver loki --log-opt loki-url="http://172.17.0.1:3100/loki/api/v1/push" alpine ping 127.0.0.1

case 1, you can stop/kill container
case 2, you can stop/kill container only after 5 mins or so

docker daemon log is not that useful either.

level=warn ts=2020-10-28T11:55:05.178484441Z caller=client.go:288 container_id=eb8c67b975f20837210c638d5f83fa1fa011c183c725af337c1fad9ffb2d3a01 component=client host=172.17.0.1:3100 msg="error sending batch, will retry" status=-1 error="Post \"http://172.17.0.1:3100/loki/api/v1/push\": dial tcp 172.17.0.1:3100: connect: connection refused"

[Pandry]

I probably figured out the reason why it takes so much time, and I can say my suspect was true and I think this is probably an intended behavior:
As we can read from the source code, the message is given inside the backoff logic loop.

If we try to start a container reducing to the (almost) minimum the backoff options, we can see the container stops (almost) immediately:
docker run --log-driver loki --log-opt loki-url="http://0.0.0.0:3100/loki/api/v1/push" --log-opt loki-time out=1s --log-opt loki-max-backoff=800ms --log-opt loki-retries=2 alpine ping 127.0.0.1
(If you want to keep the log file after the container stopped, add the --log-opt keep-file=true parameter)

_As far as my undestanding goes_ tho, if the driver is unable to send the logs withing the backoff frame, the logs will be lost (so I would consider the keep-file seriously...)

In my opinion the best thing to do would be to _cache locally the logs_ if the client is unable to send the logs within the bakeoff window, to send them later on

[kavirajk]

Agree with backoff logic,

Tested with fluentd log driver, looks like same there as well, except may be fluentd have some default lower backoff time (so that container stops more quickly). And I see this on daemon log

dockerd[1476]: time="2020-10-28T17:50:12.580014937+01:00" level=warning msg="Logger didn't exit in time: logs may be truncated"

also another small improvement could be to add a check to see if loki-url i reachable during start of the container and fail immediately.

[kavirajk]

also 5mins time limit is from the default max-backoff we use. https://github.com/grafana/loki/blob/master/pkg/promtail/client/config.go#L19

[Pandry]

also another small improvement could be to add a check to see if loki-url i reachable during start of the container and fail immediately.

I disagree, as starting a service may be more important than having its log (and debugging may not be that easy)
I would rather use a feature-flag and by default keep it disabled

As I said, in my opinion the best opinion would be to cache the logs and send them as soon as a Loki endpoint becomes available; In the meantime find a way to warn the user about the unreachable endpoint and cache the logs.

[lux4rd0]

Agree that a better way of understanding how to maintain control over a docker container when the end-point is unavailable is critical. I've been experimenting with different architecture deployments of Loki and found that even a Kill of the docker container doesn't work. Not being able to control a shutdown/restart of a container because I can't send logs out of the Loki driver shouldn't impact my container. Will look to change my container properties defaults to get around this.

[rkno82]

Maybe we should accept the behaviour of the docker driver plugin and send the logfiles to a local "kind of daemonset" promtail, which supports the loki push api?

https://grafana.com/docs/loki/latest/clients/promtail/#loki-push-api