Problems running systemd-logs plugin

[ivan4th]

Is this a BUG REPORT or FEATURE REQUEST?:
Bug report
What happened:
I tried to run sonobuoy with a config that includes just systemd-logs plugin. sonobuoy run reported that it also included e2e plugin in the run. And I was unable to get any results back.
What you expected to happen:
I was expecting sonobuoy to run just systemd-logs plugin and retrieve it's results.
How to reproduce it (as minimally and precisely as possible):
See console logs below.
Anything else we need to know?:

Environment:

• Sonobuoy tarball (which contains * below)
  I used go get -u -v github.com/heptio/sonobuoy Head is f3adf07
  Also tried sonobuoy_0.11.0-rc.2_linux_amd64.tar.gz
• Kubernetes version (use kubectl version):
  $ kubectl version
  Client Version: version.Info{Major:"1", Minor:"9+", GitVersion:"v1.9.0-alpha.3.602+b2a233b6d48e9a-dirty", GitCommit:"b2a233b6d48e9a16bc1f72bebd7308195d4f33f0", GitTreeState:"dirty", BuildDate:"2017-11-22T14:57:15Z", GoVersion:"go1.9.2", Compiler:"gc", Platform:"darwin/amd64"}
  Server Version: version.Info{Major:"1", Minor:"9", GitVersion:"v1.9.1", GitCommit:"3a1c9449a956b6026f075fa3134ff92f7d55f812", GitTreeState:"clean", BuildDate:"2018-01-04T11:40:06Z", GoVersion:"go1.9.2", Compiler:"gc", Platform:"linux/amd64"}
• Cloud provider or hardware configuration:
  none
• OS (e.g. from /etc/os-release):
  Client: Mac OS X El Capitan
  Also tried running from the master node
  k8s nodes:

VERSION="16.04.3 LTS (Xenial Xerus)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 16.04.3 LTS"
VERSION_ID="16.04"
HOME_URL="http://www.ubuntu.com/"
SUPPORT_URL="http://help.ubuntu.com/"
BUG_REPORT_URL="http://bugs.launchpad.net/ubuntu/"
VERSION_CODENAME=xenial
UBUNTU_CODENAME=xenial

• Kernel (e.g. uname -a):

Linux i4u 4.4.0-109-generic #132-Ubuntu SMP Tue Jan 9 19:52:39 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

An attempt to run systemd-logs plugin (note Running plugins: e2e, systemd-logs after sonobuoy run; I also checked the process list on the nodes to make sure get_systemd_logs.sh has completed):

ivan4th@i4mac:~/test$ cat sonobuoy.json
{
        "plugins": [ { "name": "systemd-logs" } ]
}
ivan4th@i4mac:~/test$ sonobuoy gen --config sonobuoy.json

---
apiVersion: v1
kind: Namespace
metadata:
  name: heptio-sonobuoy
---
apiVersion: v1
kind: ServiceAccount
metadata:
  labels:
    component: sonobuoy
  name: sonobuoy-serviceaccount
  namespace: heptio-sonobuoy
---
apiVersion: rbac.authorization.k8s.io/v1
kind: ClusterRoleBinding
metadata:
  labels:
    component: sonobuoy
  name: sonobuoy-serviceaccount-heptio-sonobuoy
roleRef:
  apiGroup: rbac.authorization.k8s.io
  kind: ClusterRole
  name: sonobuoy-serviceaccount
subjects:
- kind: ServiceAccount
  name: sonobuoy-serviceaccount
  namespace: heptio-sonobuoy
---
apiVersion: rbac.authorization.k8s.io/v1
kind: ClusterRole
metadata:
  labels:
    component: sonobuoy
  name: sonobuoy-serviceaccount
rules:
- apiGroups:
  - '*'
  resources:
  - '*'
  verbs:
  - '*'
---
apiVersion: v1
data:
  config.json: |
    {"Description":"","UUID":"","Version":"","ResultsDir":"","Resources":null,"Filters":{"Namespaces":"","LabelSelector":""},"Limits":{"PodLogs":{"LimitSize":"","LimitTime":""}},"Server":{"bindaddress":"","bindport":0,"advertiseaddress":"","timeoutseconds":0},"Plugins":[{"name":"systemd-logs"}],"PluginSearchPath":null,"Namespace":"heptio-sonobuoy","LoadedPlugins":null,"WorkerImage":"gcr.io/heptio-images/sonobuoy:v0.11.0-rc.2","ImagePullPolicy":"Always"}
kind: ConfigMap
metadata:
  labels:
    component: sonobuoy
  name: sonobuoy-config-cm
  namespace: heptio-sonobuoy
---
apiVersion: v1
data:
  e2e.yaml: |
    sonobuoy-config:
      driver: Job
      plugin-name: e2e
      result-type: e2e
    spec:
      env:
      - name: E2E_FOCUS
        value: '\[Conformance\]'
      - name: E2E_SKIP
        value: 'Alpha|Kubectl|\[(Disruptive|Feature:[^\]]+|Flaky)\]'
      - name: E2E_PARALLEL
        value: '1'
      command: ["/run_e2e.sh"]
      image: gcr.io/heptio-images/kube-conformance:latest
      imagePullPolicy: Always
      name: e2e
      volumeMounts:
      - mountPath: /tmp/results
        name: results
        readOnly: false
  systemd-logs.yaml: |
    sonobuoy-config:
      driver: DaemonSet
      plugin-name: systemd-logs
      result-type: systemd_logs
    spec:
      command: ["/bin/sh", "-c", "/get_systemd_logs.sh && sleep 3600"]
      env:
      - name: NODE_NAME
        valueFrom:
          fieldRef:
            fieldPath: spec.nodeName
      - name: RESULTS_DIR
        value: /tmp/results
      - name: CHROOT_DIR
        value: /node
      image: gcr.io/heptio-images/sonobuoy-plugin-systemd-logs:latest
      imagePullPolicy: Always
      name: sonobuoy-systemd-logs-config
      securityContext:
        privileged: true
      volumeMounts:
      - mountPath: /tmp/results
        name: results
        readOnly: false
      - mountPath: /node
        name: root
        readOnly: false
kind: ConfigMap
metadata:
  labels:
    component: sonobuoy
  name: sonobuoy-plugins-cm
  namespace: heptio-sonobuoy
---
apiVersion: v1
kind: Pod
metadata:
  labels:
    component: sonobuoy
    run: sonobuoy-master
    tier: analysis
  name: sonobuoy
  namespace: heptio-sonobuoy
spec:
  containers:
  - command:
    - /bin/bash
    - -c
    - /sonobuoy master --no-exit=true -v 3 --logtostderr
    env:
    - name: SONOBUOY_ADVERTISE_IP
      valueFrom:
        fieldRef:
          fieldPath: status.podIP
    image: gcr.io/heptio-images/sonobuoy:v0.11.0-rc.2
    imagePullPolicy: Always
    name: kube-sonobuoy
    volumeMounts:
    - mountPath: /etc/sonobuoy
      name: sonobuoy-config-volume
    - mountPath: /plugins.d
      name: sonobuoy-plugins-volume
    - mountPath: /tmp/sonobuoy
      name: output-volume
  restartPolicy: Never
  serviceAccountName: sonobuoy-serviceaccount
  volumes:
  - configMap:
      name: sonobuoy-config-cm
    name: sonobuoy-config-volume
  - configMap:
      name: sonobuoy-plugins-cm
    name: sonobuoy-plugins-volume
  - emptyDir: {}
    name: output-volume
---
apiVersion: v1
kind: Service
metadata:
  labels:
    component: sonobuoy
    run: sonobuoy-master
  name: sonobuoy-master
  namespace: heptio-sonobuoy
spec:
  ports:
  - port: 8080
    protocol: TCP
    targetPort: 8080
  selector:
    run: sonobuoy-master
  type: ClusterIP

ivan4th@i4mac:~/test$ sonobuoy run --config sonobuoy.json
Running plugins: e2e, systemd-logs
INFO[0001] created object                                name=heptio-sonobuoy namespace= resource=namespaces
INFO[0001] created object                                name=sonobuoy-serviceaccount namespace=heptio-sonobuoy resource=serviceaccounts
INFO[0001] created object                                name=sonobuoy-serviceaccount-heptio-sonobuoy namespace= resource=clusterrolebindings
INFO[0001] created object                                name=sonobuoy-serviceaccount namespace= resource=clusterroles
INFO[0002] created object                                name=sonobuoy-config-cm namespace=heptio-sonobuoy resource=configmaps
INFO[0002] created object                                name=sonobuoy-plugins-cm namespace=heptio-sonobuoy resource=configmaps
INFO[0002] created object                                name=sonobuoy namespace=heptio-sonobuoy resource=pods
INFO[0002] created object                                name=sonobuoy-master namespace=heptio-sonobuoy resource=services
ivan4th@i4mac:~/test$ kubectl get pods --all-namespaces -o wide -w
NAMESPACE         NAME                                                      READY     STATUS              RESTARTS   AGE       IP              NODE
default           grafana-grafana-c6bf5795d-rfdz2                           1/1       Running             1          24d       10.32.0.12      i4u
default           hass-homeassistant-7f6755774f-lgdbj                       1/1       Running             0          3d        10.32.0.15      i4u
default           influxdb-influxdb-76b7bb69b-s2kmf                         1/1       Running             0          3d        10.32.0.13      i4u
default           influxdb-influxdb-7cc6776b9d-jz5bh                        0/1       Evicted             0          25d       <none>          fionbio
default           ing-nginx-ingress-controller-2lq5k                        1/1       Running             1          8d        192.168.20.42   fionbio
default           ing-nginx-ingress-controller-9znfw                        1/1       Running             3          8d        192.168.20.61   i4u
default           ing-nginx-ingress-controller-dcqgn                        1/1       Running             0          8d        192.168.20.9    newvas
default           ing-nginx-ingress-default-backend-74f89d8857-9dxnk        1/1       Running             1          8d        10.44.0.10      fionbio
default           jenkins-jenkins-d59cb9b46-z9jpg                           1/1       Running             16         25d       10.44.0.9       fionbio
default           nfs-client-provisioner-6c8fd9c857-5kdgh                   1/1       Running             0          25d       10.32.0.10      i4u
default           wbinflux-0                                                1/1       Running             0          17d       10.32.0.11      i4u
default           zm-zoneminder-5f4b7bf6f9-shh66                            1/1       Running             0          8d        10.32.0.14      i4u
heptio-sonobuoy   sonobuoy                                                  1/1       Running             0          14s       10.44.0.12      fionbio
heptio-sonobuoy   sonobuoy-systemd-logs-daemon-set-9f2c653902b342b6-2x7jr   2/2       Running             0          5s        192.168.20.61   i4u
heptio-sonobuoy   sonobuoy-systemd-logs-daemon-set-9f2c653902b342b6-kg42b   0/2       ContainerCreating   0          5s        192.168.20.9    newvas
heptio-sonobuoy   sonobuoy-systemd-logs-daemon-set-9f2c653902b342b6-tvs9k   0/2       ContainerCreating   0          5s        192.168.20.42   fionbio
kube-system       coredns-5d55fdc494-x4rh8                                  1/1       Running             1          23d       10.44.0.11      fionbio
kube-system       kube-apiserver-i4u                                        1/1       Running             3802       41d       192.168.20.61   i4u
kube-system       kube-controller-manager-i4u                               1/1       Running             58         41d       192.168.20.61   i4u
kube-system       kube-proxy-8mvm4                                          1/1       Running             0          23d       192.168.20.61   i4u
kube-system       kube-proxy-8t25m                                          1/1       Running             1          23d       192.168.20.42   fionbio
kube-system       kube-proxy-rr6q7                                          1/1       Running             0          23d       192.168.20.9    newvas
kube-system       kube-scheduler-i4u                                        1/1       Running             31         41d       192.168.20.61   i4u
kube-system       kubernetes-dashboard-5bd6f767c7-rj9dl                     1/1       Running             0          25d       10.32.0.8       i4u
kube-system       tiller-deploy-597b878765-qcjtv                            1/1       Running             0          25d       10.32.0.9       i4u
kube-system       weave-net-jb5vc                                           2/2       Running             11         41d       192.168.20.42   fionbio
kube-system       weave-net-ll2hs                                           2/2       Running             9          41d       192.168.20.9    newvas
kube-system       weave-net-nzf6f                                           2/2       Running             8          41d       192.168.20.61   i4u
heptio-sonobuoy   sonobuoy-systemd-logs-daemon-set-9f2c653902b342b6-kg42b   2/2       Running   0         5s        192.168.20.9   newvas
heptio-sonobuoy   sonobuoy-systemd-logs-daemon-set-9f2c653902b342b6-tvs9k   2/2       Running   0         5s        192.168.20.42   fionbio
heptio-sonobuoy   sonobuoy-systemd-logs-daemon-set-9f2c653902b342b6-2x7jr   2/2       Running   0         6s        192.168.20.61   i4u
heptio-sonobuoy   sonobuoy-systemd-logs-daemon-set-9f2c653902b342b6-kg42b   2/2       Running   0         6s        192.168.20.9   newvas
heptio-sonobuoy   sonobuoy-systemd-logs-daemon-set-9f2c653902b342b6-tvs9k   2/2       Running   0         6s        192.168.20.42   fionbio



ivan4th@i4mac:~/test$ for pod in $(kubectl get pod -n heptio-sonobuoy -l component=sonobuoy -l sonobuoy-run -o name|sed 's@.*/@@'); do kubectl exec -n heptio-sonobuoy $pod -- /bin/bash -c 'ps aux|egrep "get_systemd_logs|sleep 3600"'; done
Defaulting container name to sonobuoy-systemd-logs-config.
Use 'kubectl describe pod/sonobuoy-systemd-logs-daemon-set-9f2c653902b342b6-2x7jr -n heptio-sonobuoy' to see all of the containers in this pod.
root     24611  0.0  0.0   4340   760 ?        Ss   16:49   0:00 /bin/sh -c /get_systemd_logs.sh && sleep 3600
root     24661  0.0  0.0   4240   704 ?        S    16:49   0:00 sleep 3600
root     24739  0.0  0.0   1528     4 ?        S    16:49   0:00 sleep 3600
root     24806  0.0  0.0  20052  2768 ?        Ss   16:49   0:00 /bin/bash -c ps aux|egrep "get_systemd_logs|sleep 3600"
root     24813  0.0  0.0  11132   932 ?        S    16:49   0:00 grep -E get_systemd_logs|sleep 3600
Defaulting container name to sonobuoy-systemd-logs-config.
Use 'kubectl describe pod/sonobuoy-systemd-logs-daemon-set-9f2c653902b342b6-kg42b -n heptio-sonobuoy' to see all of the containers in this pod.
root     31312  0.2  0.0   4336   744 ?        Ss   16:48   0:00 /bin/sh -c /get_systemd_logs.sh && sleep 3600
root     31350  0.0  0.0   4236   696 ?        S    16:49   0:00 sleep 3600
root     31417  0.0  0.0   1524     4 ?        S    16:49   0:00 sleep 3600
root     31438  0.0  0.1  20048  2880 ?        Ss   16:49   0:00 /bin/bash -c ps aux|egrep "get_systemd_logs|sleep 3600"
root     31444  0.0  0.0  11128   932 ?        S    16:49   0:00 grep -E get_systemd_logs|sleep 3600
Defaulting container name to sonobuoy-systemd-logs-config.
Use 'kubectl describe pod/sonobuoy-systemd-logs-daemon-set-9f2c653902b342b6-tvs9k -n heptio-sonobuoy' to see all of the containers in this pod.
root     11189  0.0  0.0   4336   736 ?        Ss   16:49   0:00 /bin/sh -c /get_systemd_logs.sh && sleep 3600
root     11232  0.0  0.0   4236   680 ?        S    16:49   0:00 sleep 3600
root     11310  0.0  0.0   1524     4 ?        S    16:49   0:00 sleep 3600
root     11339  0.0  0.0  20048  2848 ?        Ss   16:49   0:00 /bin/bash -c ps aux|egrep "get_systemd_logs|sleep 3600"
root     11345  0.0  0.0  11128  1028 ?        S    16:49   0:00 grep -E get_systemd_logs|sleep 3600
ivan4th@i4mac:~/test$ sonobuoy status
PLUGIN          STATUS  COUNT
systemd_logs    running 3

Sonobuoy is still running. Runs can take up to 60 minutes.
ivan4th@i4mac:~/test$ sonobuoy retrieve
ivan4th@i4mac:~/test$ ls -l
total 8
-rw-r--r--  1 ivan4th  staff  54 Mar 22 15:47 sonobuoy.json

Tried this also against kubeadm-dind-cluster test clusters, with similar results.
If I run sonobuoy run -mQuick however, it appears to work there as expected.

[timothysc]

Per slack - "Plugins" - https://github.com/heptio/sonobuoy/blob/master/pkg/config/config.go#L143

[ivan4th]

So a deeper issue was uncovered after some digging (see slack) - config defaulting is broken/absent, so I can get "completed" state from sonobuoy with this config:

{
  "Plugins": [ { "name": "systemd-logs" } ],
  "Server": { "bindaddress": "0.0.0.0", "bindport": 8080, "timeoutseconds": 5400 }
}

Note that I added sane defaults in "Server" section. Without it, I was getting errors like

time="2018-03-22T23:39:18Z" level=error msg="error encountered dialing master at https://10.44.0.12:0/api/v1/results/by-node/i4u/systemd_logs: Put https://10.44.0.12:0/api/v1/results/by-node/i4u/systemd_logs: dial tcp 10.44.0.12:0: getsockopt: connection refused"

in sonobuoy logs (note port 0).

Still there are perhaps more broken parts of the config as sonobuoy retrieve still gives me nothing. And also sonobuoy somehow manages to crash weave-net pods on my kubeadm cluster (they get restarted), will look into that later.

[timothysc]

/cc @liztio @chuckha

[chuckha]

The issue with run reporting the wrong plugins was fixed yesterday 815b8d7. We haven't cut a new release since so that bug still exists in the version used, but really good catch :)