Unreadable console output from time to time

[Gerrit91]

Not sure what triggers this behavior, but sometimes, this happens (removed IPs from output):

...
0\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00{\"log\":\"2021-08-03 22:00:01 +0000 UTC {\\\"DPT\\\":\\\"60104\\\",\\\"DST\\\":\\\"<censoredip>.228\\\",\\\"ID\\\":\\\"63236\\\",\\\"IN\\\":\\\"vrf104009\\\",\\\"LEN\\\":\\\"40\\\",\\\"MAC\\\":\\\"16:6d:dd:6f:ae:a6:8e:3d:ea:23:95:38:08:00\\\",\\\"OUT\\\":\\\"\\\",\\\"PREC\\\":\\\"0x00\\\",\\\"PROTO\\\":\\\"TCP\\\",\\\"RES\\\":\\\"0x00\\\",\\\"SPT\\\":\\\"46629\\\",\\\"SRC\\\":\\\"92.63.196.236\\\",\\\"SYN\\\":\\\"\\\",\\\"TOS\\\":\\\"0x08\\\",\\\"TTL\\\":\\\"241\\\",\\\"URGP\\\":\\\"0\\\",\\\"WINDOW\\\":\\\"1024\\\",\\\"timestamp\\\":\\\"2021-08-03 22:00:01 +0000 UTC\\\"}\\n\",\"stream\":\"stdout\",\"time\":\"2021-08-03T22:00:01.553956402Z\"}\n"%                                          
➜  ~ k -n firewall get pods
NAME                          READY   STATUS    RESTARTS   AGE
droptailer-5cd8999c8d-d4m9j   1/1     Running   0          98d
➜  ~ k -n firewall delete pod droptailer-5cd8999c8d-d4m9j 
pod "droptailer-5cd8999c8d-d4m9j" deleted
➜  ~ k -n firewall get pods                              
NAME                          READY   STATUS    RESTARTS   AGE
droptailer-5cd8999c8d-h75p9   1/1     Running   0          13s
➜  ~ k -n firewall logs droptailer-5cd8999c8d-h75p9 -f   
2021/08/04 13:17:51 listening on 50051
2021-08-04 13:18:07 +0000 UTC {"DPT":"14753","DST":"<censoredip>.104","ID":"5886","IN":"vrf104009","LEN":"40","MAC":"16:6d:dd:6f:ae:a6:8e:3d:ea:23:95:38:08:00","OUT":"vlan155","PREC":"0x00","PROTO":"TCP","RES":"0x00","SPT":"46436","SRC":"45.134.26.54","SYN":"","TOS":"0x00","TTL":"240","URGP":"0","WINDOW":"1024","timestamp":"2021-08-04 13:18:07 +0000 UTC"}
2021-08-04 13:18:08 +0000 UTC {"DF":"","DPT":"5060","DST":"<censoredip>.104","ID":"32394","IN":"vrf104009","LEN":"421","MAC":"16:6d:dd:6f:ae:a6:8e:3d:ea:23:95:38:08:00","OUT":"vlan155","PREC":"0x00","PROTO":"UDP","SPT":"5130","SRC":"193.107.216.129","TOS":"0x00","TTL":"52","timestamp":"2021-08-04 13:18:08 +0000 UTC"}
2021-08-04 13:18:08 +0000 UTC {"DF":"","DPT":"5060","DST":"<censoredip>.109","ID":"45980","IN":"vrf104009","LEN":"422","MAC":"16:6d:dd:6f:ae:a6:8e:3d:ea:23:95:38:08:00","OUT":"vlan155","PREC":"0x00","PROTO":"UDP","SPT":"5130","SRC":"193.107.216.129","TOS":"0x00","TTL":"52","timestamp":"2021-08-04 13:18:08 +0000 UTC"}

[mwennrich]

Not a droptailer bug, but probably a docker log-rotating bug.

Happens also with other pod-logs sometimes:

$ k logs -n shoot--project--cluster kube-apiserver-59c4464dd5-qdhkp kube-apiserver
failed to get parse function: unsupported log format: "\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\