Log tailing with `dokku logs -t [<app>]` failed to display latest log output
Closed this issue · 10 comments
Description of problem
When trying to tail the log output via dokku logs --num 1000 -t [<app>] it seems the latest output is stuck in buffer and failed to print out.
Using native command docker logs -n 1000 -f <app>web.1 is doing fine.
OS:
Distributor ID: Ubuntu
Description: Ubuntu 22.04.4 LTS
Release: 22.04
Codename: jammy
Steps to reproduce
- Create an dokku app.
- Tail the log using
dokku logs --num 1000 -t [<app>].
dokku report $APP_NAME
-----> uname: Linux Dokku 5.15.0-94-generic #104-Ubuntu SMP Tue Jan 9 15:25:40 UTC 2024 x86_64 x86_64 x86_64 GNU/Linux
-----> memory:
total used free shared buff/cache available
Mem: 3910 1551 492 2 1866 2057
Swap: 1023 246 777
-----> docker version:
Client: Docker Engine - Community
Version: 25.0.3
API version: 1.44
Go version: go1.21.6
Git commit: 4debf41
Built: Tue Feb 6 21:13:09 2024
OS/Arch: linux/amd64
Context: default
Server: Docker Engine - Community
Engine:
Version: 25.0.3
API version: 1.44 (minimum version 1.24)
Go version: go1.21.6
Git commit: f417435
Built: Tue Feb 6 21:13:09 2024
OS/Arch: linux/amd64
Experimental: false
containerd:
Version: 1.6.28
GitCommit: ae07eda36dd25f8a1b98dfbf587313b99c0190bb
runc:
Version: 1.1.12
GitCommit: v1.1.12-0-g51d5e94
docker-init:
Version: 0.19.0
GitCommit: de40ad0
-----> docker daemon info:
Client: Docker Engine - Community
Version: 25.0.3
Context: default
Debug Mode: true
Plugins:
buildx: Docker Buildx (Docker Inc.)
Version: v0.12.1
Path: /usr/libexec/docker/cli-plugins/docker-buildx
compose: Docker Compose (Docker Inc.)
Version: v2.24.5
Path: /usr/libexec/docker/cli-plugins/docker-compose
Server:
Containers: 17
Running: 16
Paused: 0
Stopped: 1
Images: 20
Server Version: 25.0.3
Storage Driver: overlay2
Backing Filesystem: extfs
Supports d_type: true
Using metacopy: false
Native Overlay Diff: true
userxattr: false
Logging Driver: json-file
Cgroup Driver: systemd
Cgroup Version: 2
Plugins:
Volume: local
Network: bridge host ipvlan macvlan null overlay
Log: awslogs fluentd gcplogs gelf journald json-file local splunk syslog
Swarm: inactive
Runtimes: io.containerd.runc.v2 runc
Default Runtime: runc
Init Binary: docker-init
containerd version: ae07eda36dd25f8a1b98dfbf587313b99c0190bb
runc version: v1.1.12-0-g51d5e94
init version: de40ad0
Security Options:
apparmor
seccomp
Profile: builtin
cgroupns
Kernel Version: 5.15.0-94-generic
Operating System: Ubuntu 22.04.4 LTS
OSType: linux
Architecture: x86_64
CPUs: 8
Total Memory: 3.819GiB
Name: Dokku
ID: CFGP:IRFR:BFS3:TGCX:F7KX:PEW2:L77V:JWON:4Z5G:D6JX:BVA4:REAY
Docker Root Dir: /var/lib/docker
Debug Mode: false
File Descriptors: 123
Goroutines: 120
System Time: 2024-02-17T13:46:53.683714264-05:00
EventsListeners: 2
Experimental: false
Insecure Registries:
127.0.0.0/8
Live Restore Enabled: false
-----> herokuish version:
herokuish: v0.7.3
buildpacks:
heroku-buildpack-multi v1.2.0
heroku-buildpack-ruby v265
heroku-buildpack-nodejs v235
heroku-buildpack-clojure v91
heroku-buildpack-python v242
heroku-buildpack-java v73
heroku-buildpack-gradle v39
heroku-buildpack-scala v96
heroku-buildpack-play v26
heroku-buildpack-php v244
heroku-buildpack-go v184
heroku-buildpack-nginx v25
buildpack-null v3
-----> dokku version: dokku version 0.33.6
-----> dokku-event-listener version: 0.15.0build+5268732
-----> dokku-update version: dokku-update 0.7.2
-----> docker-container-healthchecker version: 0.9.0
-----> docker-image-labeler version: 0.6.1build+c6e15a9
-----> git version: git version 2.34.1
-----> lambda-builder version: 0.6.0
-----> netrc version: 0.8.0build+0751c1b
! pack binary is not available
-----> plugn version: plugn: 0.13.0build+fd5297a
-----> sigil version: 0.10.1build+e443be0
-----> sshcommand version: sshcommand 0.17.1
-----> dokku plugins:
00_dokku-standard 0.33.6 enabled dokku core standard plugin
20_events 0.33.6 enabled dokku core events logging plugin
app-json 0.33.6 enabled dokku core app-json plugin
apps 0.33.6 enabled dokku core apps plugin
builder 0.33.6 enabled dokku core builder plugin
builder-dockerfile 0.33.6 enabled dokku core builder-dockerfile plugin
builder-herokuish 0.33.6 enabled dokku core builder-herokuish plugin
builder-lambda 0.33.6 enabled dokku core builder-lambda plugin
builder-nixpacks 0.33.6 enabled dokku core builder-nixpacks plugin
builder-null 0.33.6 enabled dokku core builder-null plugin
builder-pack 0.33.6 enabled dokku core builder-pack plugin
buildpacks 0.33.6 enabled dokku core buildpacks plugin
caddy-vhosts 0.33.6 enabled dokku core caddy-vhosts plugin
certs 0.33.6 enabled dokku core certificate management plugin
checks 0.33.6 enabled dokku core checks plugin
common 0.33.6 enabled dokku core common plugin
config 0.33.6 enabled dokku core config plugin
cron 0.33.6 enabled dokku core cron plugin
docker-options 0.33.6 enabled dokku core docker-options plugin
domains 0.33.6 enabled dokku core domains plugin
enter 0.33.6 enabled dokku core enter plugin
git 0.33.6 enabled dokku core git plugin
haproxy-vhosts 0.33.6 enabled dokku core haproxy-vhosts plugin
logs 0.33.6 enabled dokku core logs plugin
network 0.33.6 enabled dokku core network plugin
nginx-vhosts 0.33.6 enabled dokku core nginx-vhosts plugin
openresty-vhosts 0.33.6 enabled dokku core openresty-vhosts plugin
plugin 0.33.6 enabled dokku core plugin plugin
ports 0.33.6 enabled dokku core ports plugin
proxy 0.33.6 enabled dokku core proxy plugin
ps 0.33.6 enabled dokku core ps plugin
registry 0.33.6 enabled dokku core registry plugin
repo 0.33.6 enabled dokku core repo plugin
resource 0.33.6 enabled dokku core resource plugin
run 0.33.6 enabled dokku core run plugin
scheduler 0.33.6 enabled dokku core scheduler plugin
scheduler-docker-local 0.33.6 enabled dokku core scheduler-docker-local plugin
scheduler-k3s 0.33.6 enabled dokku core scheduler-k3s plugin
scheduler-null 0.33.6 enabled dokku core scheduler-null plugin
shell 0.33.6 enabled dokku core shell plugin
ssh-keys 0.33.6 enabled dokku core ssh-keys plugin
storage 0.33.6 enabled dokku core storage plugin
trace 0.33.6 enabled dokku core trace plugin
traefik-vhosts 0.33.6 enabled dokku core traefik-vhosts plugin
=====> api app-json information
App json computed selected: app.json
App json global selected: app.json
App json selected:
=====> api app information
App created at: 1707202686
App deploy source: git-push
App deploy source metadata: 27d4cdd915be1beee3ad02652bc91cff62b17e29
App dir: /home/dokku/api
App locked: false
=====> api builder information
Builder build dir:
Builder computed build dir:
Builder computed selected:
Builder global build dir:
Builder global selected:
Builder selected:
=====> api builder-dockerfile information
Builder dockerfile computed dockerfile path: Dockerfile
Builder dockerfile global dockerfile path: Dockerfile
Builder dockerfile dockerfile path:
=====> api builder-herokuish information
Builder herokuish computed allowed: true
Builder herokuish global allowed: true
Builder herokuish allowed:
=====> api builder-lambda information
Builder lambda computed lambdayml path: lambda.yml
Builder lambda global lambdayml path: lambda.yml
Builder lambda lambdayml path:
=====> api builder-nixpacks information
Builder nixpacks computed nixpackstoml path: nixpacks.toml
Builder nixpacks global nixpackstoml path: nixpacks.toml
Builder nixpacks nixpackstoml path:
Builder nixpacks computed no cache: false
Builder nixpacks global no cache: false
Builder nixpacks no cache:
=====> api builder-pack information
Builder pack computed projecttoml path: project.toml
Builder pack global projecttoml path: project.toml
Builder pack projecttoml path:
=====> api buildpacks information
Buildpacks computed stack: gliderlabs/herokuish:latest-22
Buildpacks global stack:
Buildpacks list:
Buildpacks stack:
=====> api caddy information
Caddy image: lucaslorentz/caddy-docker-proxy:2.8
Caddy letsencrypt email:
Caddy letsencrypt server: https://acme-v02.api.letsencrypt.org/directory
Caddy log level: ERROR
Caddy polling interval: 5s
Caddy tls internal: false
=====> api ssl information
Ssl dir: /home/dokku/api/tls
Ssl enabled: false
Ssl hostnames:
Ssl expires at:
Ssl issuer:
Ssl starts at:
Ssl subject:
Ssl verified:
=====> api checks information
Checks disabled list: none
Checks skipped list: none
Checks computed wait to retire: 60
Checks global wait to retire: 60
Checks wait to retire:
=====> api docker options information
Docker options build:
Docker options deploy: --restart=on-failure:10
Docker options run:
=====> api domains information
Domains app enabled: true
Domains app vhosts: api.Dokku
Domains global enabled: true
Domains global vhosts: Dokku
=====> api git information
Git deploy branch: master
Git global deploy branch: main
Git keep git dir: false
Git rev env var: GIT_REV
Git sha:
Git source image:
Git last updated at: 1708193498
=====> api haproxy information
Haproxy image: byjg/easy-haproxy:4.3.0
Haproxy letsencrypt email:
Haproxy letsencrypt server: https://acme-v02.api.letsencrypt.org/directory
Haproxy log level: ERROR
=====> api logs information
Logs computed max size: 10m
Logs global max size: 10m
Logs global vector sink:
Logs max size:
Logs vector global image: timberio/vector:0.35.X-debian
Logs vector sink:
=====> api network information
Network attach post create:
Network attach post deploy:
Network bind all interfaces: false
Network computed attach post create:
Network computed attach post deploy:
Network computed bind all interfaces: false
Network computed initial network:
Network computed tld:
Network global attach post create:
Network global attach post deploy:
Network global bind all interfaces: false
Network global initial network:
Network global tld:
Network initial network:
Network static web listener:
Network tld:
Network web listeners: 172.17.0.18:7007
=====> api nginx information
Nginx access log format:
Nginx computed access log format:
Nginx global access log format:
Nginx access log path:
Nginx computed access log path: /var/log/nginx/api-access.log
Nginx global access log path: /var/log/nginx/api-access.log
Nginx bind address ipv4:
Nginx computed bind address ipv4:
Nginx global bind address ipv4:
Nginx bind address ipv6:
Nginx computed bind address ipv6: ::
Nginx global bind address ipv6: ::
Nginx client max body size:
Nginx computed client max body size: 1m
Nginx global client max body size: 1m
Nginx disable custom config:
Nginx computed disable custom config: false
Nginx global disable custom config: false
Nginx error log path:
Nginx computed error log path: /var/log/nginx/api-error.log
Nginx global error log path: /var/log/nginx/api-error.log
Nginx hsts include subdomains:
Nginx computed hsts include subdomains: true
Nginx global hsts include subdomains: true
Nginx hsts max age:
Nginx computed hsts max age: 15724800
Nginx global hsts max age: 15724800
Nginx hsts preload:
Nginx computed hsts preload: false
Nginx global hsts preload: false
Nginx hsts:
Nginx computed hsts: true
Nginx global hsts: true
Nginx last visited at:
Nginx nginx conf sigil path:
Nginx computed nginx conf sigil path: nginx.conf.sigil
Nginx global nginx conf sigil path: nginx.conf.sigil
Nginx proxy buffer size:
Nginx computed proxy buffer size: 4k
Nginx global proxy buffer size: 4k
Nginx proxy buffering:
Nginx computed proxy buffering: on
Nginx global proxy buffering: on
Nginx proxy buffers:
Nginx computed proxy buffers: 8 4k
Nginx global proxy buffers: 8 4k
Nginx proxy busy buffers size:
Nginx computed proxy busy buffers size: 8k
Nginx global proxy busy buffers size: 8k
Nginx proxy read timeout:
Nginx computed proxy read timeout: 60s
Nginx global proxy read timeout: 60s
Nginx x forwarded for value:
Nginx computed x forwarded for value: $remote_addr
Nginx global x forwarded for value: $remote_addr
Nginx x forwarded port value:
Nginx computed x forwarded port value: $server_port
Nginx global x forwarded port value: $server_port
Nginx x forwarded proto value:
Nginx computed x forwarded proto value: $scheme
Nginx global x forwarded proto value: $scheme
Nginx x forwarded ssl:
Nginx computed x forwarded ssl:
Nginx global x forwarded ssl:
=====> api openresty information
Openresty access log format:
Openresty access log path: /var/log/nginx/api-access.log
Openresty bind address ipv4:
Openresty bind address ipv6: ::
Openresty client max body size:
Openresty error log path: /var/log/nginx/api-error.log
Openresty global hsts: true
Openresty computed hsts: true
Openresty hsts:
Openresty hsts include subdomains: true
Openresty hsts max age: 15724800
Openresty hsts preload: false
Openresty image: dokku/openresty-docker-proxy:0.6.0
Openresty letsencrypt email:
Openresty letsencrypt server: https://acme-v02.api.letsencrypt.org/directory
Openresty proxy buffer size: 4k
Openresty proxy buffering: on
Openresty proxy buffers: 8 4k
Openresty proxy busy buffers size: 8k
Openresty proxy read timeout: 60s
Openresty x forwarded for value: $remote_addr
Openresty x forwarded port value: $server_port
Openresty x forwarded proto value: $scheme
Openresty x forwarded ssl:
=====> api ports information
Ports map:
Ports map detected: http:7007:7007
=====> api proxy information
Proxy computed type: nginx
Proxy enabled: true
Proxy global type: nginx
Proxy type:
=====> api ps information
Deployed: true
Processes: 1
Ps can scale: true
Ps computed procfile path: Procfile
Ps global procfile path: Procfile
Ps procfile path:
Ps restart policy: on-failure:10
Restore: true
Running: true
Status web 1: running (CID: 6534010ae31)
=====> api registry information
Registry computed image repo: dokku/api
Registry computed push on release: false
Registry computed server:
Registry global image repo template:
Registry global push on release:
Registry global server:
Registry image repo:
Registry push on release:
Registry server:
Registry tag version:
=====> api resource information
=====> api scheduler information
Scheduler computed selected: docker-local
Scheduler global selected: docker-local
Scheduler selected:
=====> api scheduler-docker-local information
Scheduler docker local disable chown:
Scheduler docker local init process: true
Scheduler docker local parallel schedule count:
=====> api scheduler-k3s information
Scheduler k3s computed deploy timeout: 300s
Scheduler k3s computed image pull secrets:
Scheduler k3s computed letsencrypt server: prod
Scheduler k3s computed namespace: default
Scheduler k3s computed rollback on failure: false
Scheduler k3s deploy timeout:
Scheduler k3s global deploy timeout: 300s
Scheduler k3s global image pull secrets:
Scheduler k3s global ingress class: traefik
Scheduler k3s global letsencrypt email prod:
Scheduler k3s global letsencrypt email stag:
Scheduler k3s global letsencrypt server: prod
Scheduler k3s global namespace: default
Scheduler k3s global network interface: eth0
Scheduler k3s global rollback on failure: false
Scheduler k3s image pull secrets:
Scheduler k3s letsencrypt server:
Scheduler k3s namespace:
Scheduler k3s rollback on failure:
=====> api storage information
Storage build mounts:
Storage deploy mounts:
Storage run mounts:
=====> api traefik information
Traefik api enabled: false
Traefik api vhost: traefik.dokku.me
Traefik basic auth password:
Traefik basic auth username:
Traefik dashboard enabled: false
Traefik image: traefik:v2.10
Traefik letsencrypt email:
Traefik letsencrypt server: https://acme-v02.api.letsencrypt.org/directory
Traefik log level: ERROR
Traefik priority:
Additional information
No response
Output of failing commands after running: dokku trace:off
No response
Output of failing commands after running: dokku trace:on
No response
Thanks for the report. It's likely caused by the StreamStdio not being respected somewhere. Thats new code I've been introducing, so easy to see how it could be broken. I'll take a gander at it later today.
Not able to replicate this with k3s as the scheduler, going to try docker-local now.
Weird, I can confirm this is an issue with the docker-local plugin. Taking a look to see what could have caused that...
Ah maybe this was broken for both and I had a cached binary for my k3s testing. Going to confirm, but I have a potential fix regardless.
Okay no it works fine for k3s. I think the issue is that sed is somehow buffering the output (dunno why) but the fix is to add the -u flag to sed.
I think maybe sed is detecting a tty and buffering/not buffering based on that? This stackoverflow answer seems somewhat related, but I can't be sure since it doesn't reference the sed source and I can't find much in the sed source surrounding tty handling. https://stackoverflow.com/a/20401644/1515875
Okay, switching back to the previous method to call the plugin trigger fixes streaming. I then replaced the scheduler-logs docker-local trigger implementation with one that just calls the following:
sleep 1; while sleep 0.1; do echo $((N++)); done
This output fine in both the old and new way of calling plugin triggers, so I think there is something about the environment that is subtly different between the two that is causing sed to interact differently.
Turns out that in the old method, we never set stdin on any golang-executed subcommands. This disabled the tty, but now we always set os.Stdin. Removing the auto-stdin doesn't fix things, so there is something else going on here.
Yeah this is 100% something to do with the env being passed to sed. If we disable pretty printing via the -q flag, everything works as expected.
Looks like there are only three places we depend on this:
- the docker-local scheduler plugin, for showing logs
- the docker-local scheduler plugin, for showing run container logs
- the git plugin, when removing the ansi prefix on push
Given that, I'll just add the -u flag (we use gnu sed so this is safe) to those places. I'll keep an eye out for other places where we expect streaming and it isn't working as expected.
Closing as there is a pull request open.