NixOS VM Test Driver filter logs

Help
1

Hi, in an attempt to get my brain focused on the useful bits of test driver logs, when interactively running nixos vm tests (./result/bin/nixos-test-driver), I’d like to filter for example on kube-apiserver entries, only (see snippet below). (How) can I do that?

machine1 # [   89.387229] dhcpcd[899]: veth83bff06a: no IPv6 Routers available
machine1 # [   92.585981] dhcpcd[899]: vethc442c062: no IPv6 Routers available
machine1 # [   93.163553] dhcpcd[899]: vetheeb33a6b: no IPv6 Routers available
machine1 # [   99.359410] kube-apiserver[1147]: I0514 21:38:42.721707    1147 client.go:360] parsed scheme: "passthrough"
machine1 # [   99.374372] kube-apiserver[1147]: I0514 21:38:42.728062    1147 passthrough.go:48] ccResolverWrapper: sending update to cc: {[{https://etcd.local:2379  <nil> 0 <nil>}] <nil> <nil>}
machine1 # [   99.384252] kube-apiserver[1147]: I0514 21:38:42.728137    1147 clientconn.go:948] ClientConn switching balancer to "pick_first"
machine1 # [  122.710980] kube-addons[1804]: Error from server (NotFound): endpoints "kube-controller-manager" not found
machine1 # [  122.715264] kube-addons[1211]: INFO: Leader is
machine1 # [  123.073686] kube-addons[1211]: INFO: == Kubernetes addon ensure completed at 2021-05-14T21:39:06+00:00 ==
machine1 # [  123.075131] kube-addons[1211]: INFO: == Reconciling with deprecated label ==
machine1 # [  124.274357] kube-addons[1815]: Warning: extensions/v1beta1 Ingress is deprecated in v1.14+, unavailable in v1.22+; use networking.k8s.io/v1 Ingress
machine1 # [  124.664223] kube-addons[1816]: configmap/coredns unchanged
machine1 # [  124.666063] kube-addons[1816]: deployment.apps/coredns unchanged

While at it, is it supposed to be so that the prompt (>>>) get’s overridden by the logs, like follows? This makes it extremely hard to work with this prompt as logs pour in at high rates and make any prompt illegible.

machine1 # [  305.968045] kube-addons[1211]: INFO: == Kubernetes addon reconcile completed at 2021-05-14T21:42:09+00:00 ==
>>> machine1 # [  310.250664] kube-apiserver[1147]: I0514 21:42:13.612035    1147 client.go:360] parsed scheme: "passthrough"
machine1 # [  310.286976] kube-apiserver[1147]: I0514 21:42:13.621236    1147 passthrough.go:48] ccResolverWrapper: sending update to cc: {[{https://etcd.local:2379  <nil> 0 <nil>}] <nil> <nil>}
machine1 # [  310.289164] kube-apiserver[1147]: I0514 21:42:13.621456    1147 clientconn.go:948] ClientConn switching balancer to "pick_first"

Trying to write something on the prompt:

machine1 # [  425.878403] kube-addons[1211]: INFO: == Kubernetes addon reconcile completed at 2021-05-14T21:44:09+00:00 ==
>>> trying to write smachine1 # [  442.136714] kube-apiserver[1147]: I0514 21:44:25.500185    1147 client.go:360] parsed scheme: "passthrough"
machine1 # [  442.138227] kube-apiserver[1147]: I0514 21:44:25.501797    1147 passthrough.go:48] ccResolverWrapper: sending update to cc: {[{https://etcd.local:2379  <nil> 0 <nil>}] <nil> <nil>}
machine1 # [  442.141680] kube-apiserver[1147]: I0514 21:44:25.501824    1147 clientconn.go:948] ClientConn switching balancer to "pick_first"
o
1 Like
2

I went ahead and tried something towards starting to fix this (no definite solution, yet).

One question left is: how can we get the testing VM’s systemd to emit logs in a parseable format, so that we can emit them as structured logs while applying filters on certain attributes? (I understand that with LOGFILE env handle a logfile in XML is written to that location, but I’m asking in the context of an interactively run vm test for debugging)

At least the first part of the logs seem pretty structured in all cases:
machine1 # [ 425.878403] kube-addons[1211]:

https://github.com/NixOS/nixpkgs/pull/123052

1 Like