k3s下查看容器日志，换行格式混乱 #60

huapox · 2021-03-08T12:07:25Z

[root@(⎈ |default:kube-web) /]$ kc logs -f --tail=20 goldpinger-vssjq
{"level":"info","ts":1615175439.9033206,"caller":"goldpinger/pinger.go:159","msg":"Starting pinger","op":"pinger","name":"goldpinger-vssjq","hostIP":"3.4.5.2","podIP":"","period":30,"initialWait":15,"jitterFactor":0.05}
{"level":"warn","ts":1615175439.9035208,"caller":"goldpinger/pinger.go:151","msg":"Ping returned error","op":"pinger","name":"goldpinger-mrx67","hostIP":"3.4.5.2","podIP":"10.42.0.9","responseTime":0.000411561,"error":"Get \"http://10.42.0.9:80/ping\": dial tcp 10.42.0.9:80: connect: no route to host"}
{"level":"warn","ts":1615175447.7036345,"caller":"goldpinger/pinger.go:151","msg":"Ping returned error","op":"pinger","name":"goldpinger-4wr78","hostIP":"3.4.5.3","podIP":"10.42.1.6","responseTime":0.300109295,"error":"Get \"http://10.42.1.6:80/ping\": context deadline exceeded"}
{"level":"warn","ts":1615175454.9034328,"caller":"goldpinger/pinger.go:84","msg":"Could not get client","op":"pinger","name":"goldpinger-vssjq","hostIP":"3.4.5.2","podIP":"","error":"Host or pod IP empty, can't make a call"}
{"level":"warn","ts":1615175462.40329,"caller":"goldpinger/pinger.go:84","msg":"Could not get client","op":"pinger","name":"goldpinger-tqwqg","hostIP":"3.4.5.3","podIP":"","error":"Host or pod IP empty, can't make a call"}
{"level":"info","ts":1615175469.9066997,"caller":"goldpinger/updater.go:128","msg":"Deleting pod from pingers","name":"goldpinger-vssjq","podIP":"","hostIP":"3.4.5.2"}
{"level":"info","ts":1615175469.9067352,"caller":"goldpinger/updater.go:128","msg":"Deleting pod from pingers","name":"goldpinger-tqwqg","podIP":"","hostIP":"3.4.5.3"}
{"level":"info","ts":1615175469.9067416,"caller":"goldpinger/updater.go:107","msg":"Starting pingers for new pods","numNewPods":2,"refreshPeriod":30,"waitPeriod":15,"JitterFactor":0.05}
{"level":"info","ts":1615175469.906774,"caller":"goldpinger/pinger.go:159","msg":"Starting pinger","op":"pinger","name":"goldpinger-tqwqg","hostIP":"3.4.5.3","podIP":"10.42.3.3","period":30,"initialWait":15,"jitterFactor":0.05}
{"level":"info","ts":1615175469.9067938,"caller":"goldpinger/pinger.go:159","msg":"Starting pinger","op":"pinger","name":"goldpinger-vssjq","hostIP":"3.4.5.2","podIP":"10.42.2.3","period":30,"initialWait":0,"jitterFactor":0.05}
{"level":"warn","ts":1615175470.8107235,"caller":"goldpinger/pinger.go:151","msg":"Ping returned error","op":"pinger","name":"goldpinger-mrx67","hostIP":"3.4.5.2","podIP":"10.42.0.9","responseTime":0.000450583,"error":"Get \"http://10.42.0.9:80/ping\": dial tcp 10.42.0.9:80: connect: no route to host"}
{"level":"warn","ts":1615175479.114571,"caller":"goldpinger/pinger.go:151","msg":"Ping returned error","op":"pinger","name":"goldpinger-4wr78","hostIP":"3.4.5.3","podIP":"10.42.1.6","responseTime":0.300135316,"error":"Get \"http://10.42.1.6:80/ping\": dial tcp 10.42.1.6:80: i/o timeout"}
{"level":"warn","ts":1615175501.840936,"caller":"goldpinger/pinger.go:151","msg":"Ping returned error","op":"pinger","name":"goldpinger-mrx67","hostIP":"3.4.5.2","podIP":"10.42.0.9","responseTime":0.000343806,"error":"Get \"http://10.42.0.9:80/ping\": dial tcp 10.42.0.9:80: connect: no route to host"}
{"level":"warn","ts":1615175509.2131298,"caller":"goldpinger/pinger.go:151","msg":"Ping returned error","op":"pinger","name":"goldpinger-4wr78","hostIP":"3.4.5.3","podIP":"10.42.1.6","responseTime":0.300135966,"error":"Get \"http://10.42.1.6:80/ping\": dial tcp 10.42.1.6:80: i/o timeout"}
{"level":"warn","ts":1615175532.292389,"caller":"goldpinger/pinger.go:151","msg":"Ping returned error","op":"pinger","name":"goldpinger-mrx67","hostIP":"3.4.5.2","podIP":"10.42.0.9","responseTime":0.000330327,"error":"Get \"http://10.42.0.9:80/ping\": dial tcp 10.42.0.9:80: connect: no route to host"}
{"level":"warn","ts":1615175539.9861126,"caller":"goldpinger/pinger.go:151","msg":"Ping returned error","op":"pinger","name":"goldpinger-4wr78","hostIP":"3.4.5.3","podIP":"10.42.1.6","responseTime":0.300149933,"error":"Get \"http://10.42.1.6:80/ping\": context deadline exceeded"}
{"level":"warn","ts":1615175563.1632693,"caller":"goldpinger/pinger.go:151","msg":"Ping returned error","op":"pinger","name":"goldpinger-mrx67","hostIP":"3.4.5.2","podIP":"10.42.0.9","responseTime":0.300122017,"error":"Get \"http://10.42.0.9:80/ping\": context deadline exceeded"}
{"level":"warn","ts":1615175570.4632773,"caller":"goldpinger/pinger.go:151","msg":"Ping returned error","op":"pinger","name":"goldpinger-4wr78","hostIP":"3.4.5.3","podIP":"10.42.1.6","responseTime":0.300147665,"error":"Get \"http://10.42.1.6:80/ping\": context deadline exceeded"}
{"level":"info","ts":1615175589.932876,"caller":"goldpinger/updater.go:128","msg":"Deleting pod from pingers","name":"goldpinger-mrx67","podIP":"10.42.0.9","hostIP":"3.4.5.2"}
{"level":"info","ts":1615175589.9329145,"caller":"goldpinger/updater.go:128","msg":"Deleting pod from pingers","name":"goldpinger-4wr78","podIP":"10.42.1.6","hostIP":"3.4.5.3"}

wrfly · 2021-03-08T16:17:38Z

啊，这个的确很头疼，应该是少输出了一个换行，我抽空瞅瞅，看怎么加回来。

wrfly · 2021-03-08T16:21:59Z

BTW, 换个别的image也会出现同样的问题吗，比如nginx？

huapox · 2021-03-09T02:23:20Z

BTW, 换个别的image也会出现同样的问题吗，比如nginx？

polaris(一行)

time="2021-03-08T03:53:09Z" level=info msg="Starting Polaris dashboard server on port 8080"

coredns

.:53
    [INFO] plugin/reload: Running configuration MD5 = 4665410bf21c8b272fcfd562c482cb82
                                                                                         ______                ____  _   _______
                                                                                                                                  / ____/___  ________  / __ \/ | / / ___/ ~ CoreDNS-1.6.3
               / /   / __ \/ ___/ _ \/ / / /  |/ /\__ \         ~ linux/amd64, go1.12.9, 37b9550
                                                                                                / /___/ /_/ / /  /  __/ /_/ / /|  /___/ / 
                                                                                                                                          \____/\____/_/   \___/_____/_/ |_//____/

dnsmasq

[webproc] 2021/03/08 03:53:13 loaded config files changes from disk
                                                                   [webproc] 2021/03/08 03:53:13 agent listening on http://0.0.0.0:8080...
                                                                                                                                          dnsmasq: started, version 2.80 cachesize 150
          dnsmasq: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth no-DNSSEC loop-detect inotify dumpfile
                                                                                                                                                                      dnsmasq: using nameserver 10.0.0.1#53 for domain company 
                                                   dnsmasq: using nameserver 8.8.8.8#53
                                                                                       dnsmasq: using nameserver 114.114.114.114#53
                                                                                                                                   dnsmasq: read /etc/hosts - 7 addresses

huapox · 2021-03-09T02:29:47Z

大多只是每行多了空格，还好做匹配处理

coredns

coredns那显示效果过分了啊..~

[root@(⎈ |default:kube-system) /]$ kc logs -f --tail=20 coredns-6c6bb68b64-bjlgd 
.:53
[INFO] plugin/reload: Running configuration MD5 = 4665410bf21c8b272fcfd562c482cb82
   ______                ____  _   _______
  / ____/___  ________  / __ \/ | / / ___/	~ CoreDNS-1.6.3
 / /   / __ \/ ___/ _ \/ / / /  |/ /\__ \ 	~ linux/amd64, go1.12.9, 37b9550
/ /___/ /_/ / /  /  __/ /_/ / /|  /___/ / 
\____/\____/_/   \___/_____/_/ |_//____/

#coredns 手工清理行首空格(不能完全匹配)
.:53
[INFO] plugin/reload: Running configuration MD5 = 4665410bf21c8b272fcfd562c482cb82
______                ____  _   _______
/ ____/___  ________  / __ \/ | / / ___/ ~ CoreDNS-1.6.3
/ /   / __ \/ ___/ _ \/ / / /  |/ /\__ \         ~ linux/amd64, go1.12.9, 37b9550
/ /___/ /_/ / /  /  __/ /_/ / /|  /___/ / 
\____/\____/_/   \___/_____/_/ |_//____/

dnsmasq 手工清理行首空格

[webproc] 2021/03/08 03:53:13 loaded config files changes from disk
[webproc] 2021/03/08 03:53:13 agent listening on http://0.0.0.0:8080...
dnsmasq: started, version 2.80 cachesize 150
dnsmasq: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth no-DNSSEC loop-detect inotify dumpfile
dnsmasq: using nameserver 10.0.0.1#53 for domain company 
dnsmasq: using nameserver 8.8.8.8#53
dnsmasq: using nameserver 114.114.114.114#53
dnsmasq: read /etc/hosts - 7 addresses

wrfly · 2021-03-13T17:31:12Z

我debug了一下，是因为这些容器的输出少了 \r\n，换一个简单的容器，比如 wrfly/echo 试试，日志就应该正常了。

感觉这个问题除了从容器角度修改，没有办法解决，logs是一次性输出了很多日志，无法判断哪个是新的一行。如果只从fix当前问题考虑的话，可以在 \r 后面追加一个 \n, 但是这样就修改原始日志了，我不确定这是一个好的方法。

wrfly · 2021-03-13T17:34:11Z

tail /var/lib/docker/containers/470eeb1c4b3e64caf67aedc67b2b24304012a22ee559aa3ffdbf51f0a62a6dca/470eeb1c4b3e64caf67aedc67b2b24304012a22ee559aa3ffdbf51f0a62a6dca-json.log
{"log":"          `-._        _.-'                                           \r\n","stream":"stdout","time":"2021-03-13T16:36:14.253970513Z"}
{"log":"              `-.__.-'                                               \r\n","stream":"stdout","time":"2021-03-13T16:36:14.253974316Z"}
{"log":"\r\n","stream":"stdout","time":"2021-03-13T16:36:14.253978398Z"}
{"log":"1:M 13 Mar 2021 16:36:14.253 # Server initialized\r\n","stream":"stdout","time":"2021-03-13T16:36:14.253982264Z"}
{"log":"1:M 13 Mar 2021 16:36:14.253 # WARNING overcommit_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.\r\n","stream":"stdout","time":"2021-03-13T16:36:14.253987746Z"}
{"log":"1:M 13 Mar 2021 16:36:14.253 * Loading RDB produced by version 6.0.10\r\n","stream":"stdout","time":"2021-03-13T16:36:14.253995756Z"}
{"log":"1:M 13 Mar 2021 16:36:14.253 * RDB age 8360 seconds\r\n","stream":"stdout","time":"2021-03-13T16:36:14.254064352Z"}
{"log":"1:M 13 Mar 2021 16:36:14.253 * RDB memory usage when created 0.77 Mb\r\n","stream":"stdout","time":"2021-03-13T16:36:14.254076763Z"}
{"log":"1:M 13 Mar 2021 16:36:14.253 * DB loaded from disk: 0.000 seconds\r\n","stream":"stdout","time":"2021-03-13T16:36:14.254090025Z"}
{"log":"1:M 13 Mar 2021 16:36:14.253 * Ready to accept connections\r\n","stream":"stdout","time":"2021-03-13T16:36:14.254094666Z"}

docker 原始日志文件里面都有一个 \r\n，所以在浏览器上也可以正常显示。

huapox · 2021-03-17T10:15:10Z

我debug了一下，是因为这些容器的输出少了 \r\n，换一个简单的容器，比如 wrfly/echo 试试，日志就应该正常了。

感觉这个问题除了从容器角度修改，没有办法解决，logs是一次性输出了很多日志，无法判断哪个是新的一行。如果只从fix当前问题考虑的话，可以在 \r 后面追加一个 \n, 但是这样就修改原始日志了，我不确定这是一个好的方法。

ar 17 10:13:35 UTC 2021
                       Wed Mar 17 10:13:36 UTC 2021
                                                   Wed Mar 17 10:13:37 UTC 2021
                                                                               Wed Mar 17 10:13:38 UTC 2021
                                                                                                           Wed Mar 17 10:13:39 UTC 2021
                                                                                                                                       Wed Mar 17 10:13:40 UTC 2021
                                                                                                                                                                   Wed Mar 17 10:13:41 UTC 2021
                   Wed Mar 17 10:13:42 UTC 2021
                                               Wed Mar 17 10:13:43 UTC 2021
                                                                           Wed Mar 17 10:13:44 UTC 2021
                                                                                                       Wed Mar 17 10:13:45 UTC 2021
                                                                                                                                   Wed Mar 17 10:13:46 UTC 2021
                                                                                                                                                               Wed Mar 17 10:13:47 UTC 2021
               Wed Mar 17 10:13:48 UTC 2021
                                           Wed Mar 17 10:13:49 UTC 2021
                                                                       Wed Mar 17 10:13:50 UTC 2021

也不行

wrfly · 2021-09-11T14:53:45Z

Hi @huapox 我升级了一下所有的依赖库 (docker/k8s) 你pull一下最新的image看有没有fix这个issue

huapox · 2021-10-16T04:55:17Z

Hi @huapox 我升级了一下所有的依赖库 (docker/k8s) 你pull一下最新的image看有没有fix这个issue

感谢，晚些时间验证后回复

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

k3s下查看容器日志，换行格式混乱 #60

k3s下查看容器日志，换行格式混乱 #60

huapox commented Mar 8, 2021

wrfly commented Mar 8, 2021

wrfly commented Mar 8, 2021

huapox commented Mar 9, 2021

huapox commented Mar 9, 2021 •

edited

Loading

wrfly commented Mar 13, 2021

wrfly commented Mar 13, 2021

huapox commented Mar 17, 2021

wrfly commented Sep 11, 2021

huapox commented Oct 16, 2021

k3s下查看容器日志，换行格式混乱 #60

k3s下查看容器日志，换行格式混乱 #60

Comments

huapox commented Mar 8, 2021

wrfly commented Mar 8, 2021

wrfly commented Mar 8, 2021

huapox commented Mar 9, 2021

huapox commented Mar 9, 2021 • edited Loading

wrfly commented Mar 13, 2021

wrfly commented Mar 13, 2021

huapox commented Mar 17, 2021

wrfly commented Sep 11, 2021

huapox commented Oct 16, 2021

huapox commented Mar 9, 2021 •

edited

Loading