k3d and kubeedge (kubectl logs) not working

[siredmar]

Hi!
I'm trying to get kubeedge working in a k3d cluster.

Introduction

Kubeedge allows putting devices, e.g. raspberry pi as node an existing cluster. This allows scheduling workload on these edge nodes and be running even if the device is temporary disconnected from the cluster. There is one part running on the edge devices communication with the other part running in the cluster. The cloud component proxies everything needed for the edge nodes.
Because edge nodes might not be in the same network as the rest of the cluster there is an iptables rule running on the node running the cluster API server that redirects all requests for edge nodes kubelet to the kubeege cloud components stream server port 10003.

See details for the iptables rule

$ docker exec -it k3d-edgefarm-core-server-0 sh                                                          
/ # iptables -L TUNNEL-PORT -t nat 
Chain TUNNEL-PORT (2 references)
target     prot opt source               destination         
DNAT       tcp  --  anywhere             anywhere             tcp dpt:10351 to:192.168.224.4:10003

Environment

The environment is setup using devspace and k3d. The kubeedge devices are pure virtual as docker containers running on the same developer machine. See detail section for more information about the running cluster with two virtual nodes and a demo application running on these nodes.

Kubeconfig:

apiVersion: v1
clusters:
- cluster:
    certificate-authority-data: LS0tLS1CRUdJTiBDRVJUSUZJQ0FURS0tLS0tCk1JSUJkekNDQVIyZ0F3SUJBZ0lCQURBS0JnZ3Foa2pPUFFRREFqQWpNU0V3SHdZRFZRUUREQmhyTTNNdGMyVnkKZG1WeUxXTmhRREUyTkRZeU1UUXdOemt3SGhjTk1qSXdNekF5TURrME1URTVXaGNOTXpJd01qSTRNRGswTVRFNQpXakFqTVNFd0h3WURWUVFEREJock0zTXRjMlZ5ZG1WeUxXTmhRREUyTkRZeU1UUXdOemt3V1RBVEJnY3Foa2pPClBRSUJCZ2dxaGtqT1BRTUJCd05DQUFUVllncCtjdXpqSHhaTmZlc2tiemRTMnFEc0VrSm5YT3loR0E4cUJoWnkKcTdGVkMrQlI2UzJ0ZXk2WHU1MW9BYVFEREEwQTdORDlDQ1pFQWFvbjZqdThvMEl3UURBT0JnTlZIUThCQWY4RQpCQU1DQXFRd0R3WURWUjBUQVFIL0JBVXdBd0VCL3pBZEJnTlZIUTRFRmdRVU84cVZtZ0hpeFlpejl0WThXaXNECitkcVBRQlF3Q2dZSUtvWkl6ajBFQXdJRFNBQXdSUUloQU1YOVMrdWJZcjN4WHZSQ3VtOHVpcCtWY0tKNXF4dnAKR091TnRRTTBuempWQWlCUjNuQzNDbHpzOFA2VHRwMEZvZGt6VWlURkRwYXlGVkl4RnNkeThKeUd4QT09Ci0tLS0tRU5EIENFUlRJRklDQVRFLS0tLS0K
    server: https://0.0.0.0:30550
  name: k3d-edgefarm-core
contexts:
- context:
    cluster: k3d-edgefarm-core
    namespace: kubeedge
    user: admin@k3d-edgefarm-core
  name: k3d-edgefarm-core
current-context: k3d-edgefarm-core
kind: Config
preferences: {}
users:
- name: admin@k3d-edgefarm-core
  user:
    client-certificate-data: LS0tLS1CRUdJTiBDRVJUSUZJQ0FURS0tLS0tCk1JSUJrRENDQVRlZ0F3SUJBZ0lJU2k4enowNFpGbjB3Q2dZSUtvWkl6ajBFQXdJd0l6RWhNQjhHQTFVRUF3d1kKYXpOekxXTnNhV1Z1ZEMxallVQXhOalEyTWpFME1EYzVNQjRYRFRJeU1ETXdNakE1TkRFeE9Wb1hEVEl6TURNdwpNakE1TkRFeE9Wb3dNREVYTUJVR0ExVUVDaE1PYzNsemRHVnRPbTFoYzNSbGNuTXhGVEFUQmdOVkJBTVRESE41CmMzUmxiVHBoWkcxcGJqQlpNQk1HQnlxR1NNNDlBZ0VHQ0NxR1NNNDlBd0VIQTBJQUJNM1VrN0dCVkJqeWoyeFEKdkZvbE9HeXU5UU1aSkl0Y0gveHgrclRRNmVMQXBMVFV5SUlCZ3BZMlNqWng0ZXNHNVdQb1ZzNjVZZFdVYjNzVgprVWoyZ3V5alNEQkdNQTRHQTFVZER3RUIvd1FFQXdJRm9EQVRCZ05WSFNVRUREQUtCZ2dyQmdFRkJRY0RBakFmCkJnTlZIU01FR0RBV2dCVGFpdmJnb0cva0pqb3YzeXIrN3JJWmdaSmZRREFLQmdncWhrak9QUVFEQWdOSEFEQkUKQWlBZytKd2JjVE8wZGttWjEvU2l0VVV3bWhETlRacHY3ZzBCMytZYW84dWpLd0lnYmp2UjE2c3hrT09wdkJoegpzY2Jvd1IxQVUrMGtwcDhUYi9SZHMxMlUzU009Ci0tLS0tRU5EIENFUlRJRklDQVRFLS0tLS0KLS0tLS1CRUdJTiBDRVJUSUZJQ0FURS0tLS0tCk1JSUJkekNDQVIyZ0F3SUJBZ0lCQURBS0JnZ3Foa2pPUFFRREFqQWpNU0V3SHdZRFZRUUREQmhyTTNNdFkyeHAKWlc1MExXTmhRREUyTkRZeU1UUXdOemt3SGhjTk1qSXdNekF5TURrME1URTVXaGNOTXpJd01qSTRNRGswTVRFNQpXakFqTVNFd0h3WURWUVFEREJock0zTXRZMnhwWlc1MExXTmhRREUyTkRZeU1UUXdOemt3V1RBVEJnY3Foa2pPClBRSUJCZ2dxaGtqT1BRTUJCd05DQUFRRkM1RElzVzhxREM3a2xuUUM1TkppUEdQblVSdkdaL1JhVlJRd01lSm4KN1FsaTJUVlJKWkZPZUJCNHJpTVBORVZDSlhpQ0dWeHRCR0NOakpMODFyZ2pvMEl3UURBT0JnTlZIUThCQWY4RQpCQU1DQXFRd0R3WURWUjBUQVFIL0JBVXdBd0VCL3pBZEJnTlZIUTRFRmdRVTJvcjI0S0J2NUNZNkw5OHEvdTZ5CkdZR1NYMEF3Q2dZSUtvWkl6ajBFQXdJRFNBQXdSUUlnTWxsbHJQa29CWXdvUGd1c3pHNTRaS2xnZi90LzRGaWwKOVVhWnRML29MdzRDSVFEUXFOUUFmUmpUMWx2NlY5MEpTSDRLa2h4Z0xXVkJUYjEvQlBJV3pHYnZhQT09Ci0tLS0tRU5EIENFUlRJRklDQVRFLS0tLS0K
    client-key-data: LS0tLS1CRUdJTiBFQyBQUklWQVRFIEtFWS0tLS0tCk1IY0NBUUVFSUdhallVMWVYUmp5amRjQ3lUUHRuT1J4b2RvYnB3ZTN1MG1Pa2x2ODVGeXNvQW9HQ0NxR1NNNDkKQXdFSG9VUURRZ0FFemRTVHNZRlVHUEtQYkZDOFdpVTRiSzcxQXhra2kxd2YvSEg2dE5EcDRzQ2t0TlRJZ2dHQwpsalpLTm5IaDZ3YmxZK2hXenJsaDFaUnZleFdSU1BhQzdBPT0KLS0tLS1FTkQgRUMgUFJJVkFURSBLRVktLS0tLQo=

Nodes:

$kubectl get nodes -o wide
NAME                         STATUS   ROLES                  AGE    VERSION                   INTERNAL-IP     EXTERNAL-IP   OS-IMAGE           KERNEL-VERSION          CONTAINER-RUNTIME
k3d-edgefarm-core-server-0   Ready    control-plane,master   31m    v1.20.12+k3s1             192.168.224.4   <none>        Unknown            5.8.18-050818-generic   containerd://1.4.11-k3s1
k3d-edgefarm-core-agent-0    Ready    <none>                 31m    v1.20.12+k3s1             192.168.224.3   <none>        Unknown            5.8.18-050818-generic   containerd://1.4.11-k3s1
node1                        Ready    agent,edge             101s   v1.19.3-kubeedge-v1.9.1   172.17.0.3      <none>        Ubuntu 20.04 LTS   5.8.18-050818-generic   docker://19.3.11
node2                        Ready    agent,edge             101s   v1.19.3-kubeedge-v1.9.1   172.17.0.6      <none>        Ubuntu 20.04 LTS   5.8.18-050818-generic   docker://19.3.11

Kubeedge Pods:

$ kubectl get pods -n kubeedge -o wide
NAME                         READY   STATUS    RESTARTS   AGE     IP              NODE                         NOMINATED NODE   READINESS GATES
cloudcore-65747b9d69-79q4m   1/1     Running   0          29m     192.168.224.4   k3d-edgefarm-core-server-0   <none>           <none>

Pods after apply demo application:

kubectl get pods -n kubeedge -o wide
NAME                         READY   STATUS    RESTARTS   AGE     IP              NODE                         NOMINATED NODE   READINESS GATES
cloudcore-65747b9d69-79q4m   1/1     Running   0          29m     192.168.224.4   k3d-edgefarm-core-server-0   <none>           <none>
nginx-9shxd                  1/1     Running   0          2m10s   172.18.0.2      node1                        <none>           <none>
nginx-9ph7q                  1/1     Running   0          2m10s   172.18.0.2      node2                        <none>           <none>

Docker containers running locally:

$ docker ps                     
CONTAINER ID   IMAGE                            COMMAND                  CREATED             STATUS             PORTS                                                                                                                                                                                                                               NAMES
27dd586be4b1   edgefarm/virtual-device:latest   "/usr/local/bin/entr…"   46 minutes ago      Up 46 minutes                                                                                                                                                                                                                                          node2
d1d3c0846291   edgefarm/virtual-device:latest   "/usr/local/bin/entr…"   46 minutes ago      Up 46 minutes                                                                                                                                                                                                                                          node1
3a25d557d295   rancher/k3d-proxy:5.3.0          "/bin/sh -c nginx-pr…"   About an hour ago   Up About an hour   0.0.0.0:10000->10000/tcp, :::10000->10000/tcp, 0.0.0.0:10002-10004->10002-10004/tcp, :::10002-10004->10002-10004/tcp, 0.0.0.0:30080->80/tcp, :::30080->80/tcp, 0.0.0.0:30443->443/tcp, :::30443->443/tcp, 0.0.0.0:30550->6443/tcp   k3d-edgefarm-core-serverlb
b304232c4045   rancher/k3s:v1.20.12-k3s1        "/bin/k3s agent"         About an hour ago   Up About an hour                                                                                                                                                                                                                                       k3d-edgefarm-core-agent-0
396174bece53   rancher/k3s:v1.20.12-k3s1        "/bin/k3s server --d…"   About an hour ago   Up About an hour                                                                                                                                                                                                                                       k3d-edgefarm-core-server-0
29e21aec25f2   registry:2                       "/entrypoint.sh /etc…"   23 hours ago        Up 23 hours        0.0.0.0:5000->5000/tcp                                                                                                                                                                                                              k3d-registry.k3d.localhost

What is the problem?

kubectl logs does not work for pods running on edge nodes.

$ kubectl logs nginx-9shxd -n kubeedge
Error from server: Get "https://node1:10351/containerLogs/kubeedge/nginx-9shxd/nginx": dial tcp: lookup node1: no such host

However, what works is directly using curl to get the logs from the api server.

$ SECRET=$(kubectl -n kubeedge get secrets| grep cloudcore-token | awk -F " " '{print $1}')
$ TOKEN=$(k get secrets ${SECRET} -o jsonpath='{.data.token}' | base64 -d)
$ ADDRESS=$(docker inspect -f '{{range .NetworkSettings.Networks}}{{.IPAddress}}{{end}}' k3d-edgefarm-core-server-0 | sed -e 's/\./\-/g'  | sed -e 's/$/.nip.io/')
$ echo $ADDRESS
192-168-224-4.nip.io
$ curl -v -H "Authorization: ${TOKEN}" "https://${ADDRESS}:10003/containerLogs/kubeedge/nginx-9shxd/nginx"
/docker-entrypoint.sh: /docker-entrypoint.d/ is not empty, will attempt to perform configuration
/docker-entrypoint.sh: Looking for shell scripts in /docker-entrypoint.d/
/docker-entrypoint.sh: Launching /docker-entrypoint.d/10-listen-on-ipv6-by-default.sh
10-listen-on-ipv6-by-default.sh: info: Getting the checksum of /etc/nginx/conf.d/default.conf
10-listen-on-ipv6-by-default.sh: info: Enabled listen on IPv6 in /etc/nginx/conf.d/default.conf
/docker-entrypoint.sh: Launching /docker-entrypoint.d/20-envsubst-on-templates.sh
/docker-entrypoint.sh: Launching /docker-entrypoint.d/30-tune-worker-processes.sh
/docker-entrypoint.sh: Configuration complete; ready for start up
2022/03/02 10:11:39 [notice] 1#1: using the "epoll" event method
2022/03/02 10:11:39 [notice] 1#1: nginx/1.21.6
...

So the strange about this is that it tries to get the logs directly from the node node1 and does not try to contact the api server.
However, In an RKE1 setup the kubectl logs command directly talks to the API server not to the edge node.

See details section for a little bit more verbose output and an RKE1 comparison.

This is the output running k3d:

$ kubectl logs nginx-9ph7q -v9 -n kubeedge
...
I0302 11:50:03.493974 1808797 round_trippers.go:425] curl -k -v -XGET  -H "Accept: application/json, */*" -H "User-Agent: kubectl/v1.20.12 (linux/amd64) kubernetes/4bf2e32" 'https://0.0.0.0:30550/api/v1/namespaces/kubeedge/pods/nginx-9ph7q'
I0302 11:50:03.501394 1808797 round_trippers.go:445] GET https://0.0.0.0:30550/api/v1/namespaces/kubeedge/pods/nginx-9ph7q 200 OK in 7 milliseconds
I0302 11:50:03.501435 1808797 round_trippers.go:451] Response Headers:
I0302 11:50:03.501449 1808797 round_trippers.go:454]     Cache-Control: no-cache, private
I0302 11:50:03.501462 1808797 round_trippers.go:454]     Content-Type: application/json
I0302 11:50:03.501474 1808797 round_trippers.go:454]     X-Kubernetes-Pf-Flowschema-Uid: 7bcb8f39-41f0-49fa-9806-f599f410ebc4
I0302 11:50:03.501486 1808797 round_trippers.go:454]     X-Kubernetes-Pf-Prioritylevel-Uid: 3a4f3aa8-6fea-4c59-825b-239bbbe9588b
I0302 11:50:03.501498 1808797 round_trippers.go:454]     Date: Wed, 02 Mar 2022 10:50:03 GMT
I0302 11:50:03.501643 1808797 request.go:1107] Response Body: {"kind":"Pod","apiVersion":"v1","metadata":{"name":"nginx-9ph7q","generateName":"nginx-","namespace":"kubeedge","uid":"51a3f2fb-f9a0-4089-b914-0e4691bf3487","resourceVersion":"7674","creationTimestamp":"2022-03-02T10:11:02Z","labels":{"app":"nginx","controller-revision-hash":"5d477c5d4c","pod-template-generation":"1"},"ownerReferences":[{"apiVersion":"apps/v1","kind":"DaemonSet","name":"nginx","uid":"633fa88e-7678-4b96-8d5b-adeccd60adae","controller":true,"blockOwnerDeletion":true}],"managedFields":[{"manager":"k3s","operation":"Update","apiVersion":"v1","time":"2022-03-02T10:11:02Z","fieldsType":"FieldsV1","fieldsV1":{"f:metadata":{"f:generateName":{},"f:labels":{".":{},"f:app":{},"f:controller-revision-hash":{},"f:pod-template-generation":{}},"f:ownerReferences":{".":{},"k:{\"uid\":\"633fa88e-7678-4b96-8d5b-adeccd60adae\"}":{".":{},"f:apiVersion":{},"f:blockOwnerDeletion":{},"f:controller":{},"f:kind":{},"f:name":{},"f:uid":{}}}},"f:spec":{"f:affinity":{".":{},"f:nodeAffinity":{".":{},"f:requiredDuringSchedulingIgnoredDuringExecution":{".":{},"f:nodeSelectorTerms":{}}}},"f:containers":{"k:{\"name\":\"nginx\"}":{".":{},"f:image":{},"f:imagePullPolicy":{},"f:name":{},"f:resources":{},"f:terminationMessagePath":{},"f:terminationMessagePolicy":{}}},"f:dnsPolicy":{},"f:enableServiceLinks":{},"f:restartPolicy":{},"f:schedulerName":{},"f:securityContext":{},"f:terminationGracePeriodSeconds":{},"f:tolerations":{}}}},{"manager":"cloudcore","operation":"Update","apiVersion":"v1","time":"2022-03-02T10:11:42Z","fieldsType":"FieldsV1","fieldsV1":{"f:status":{"f:conditions":{"k:{\"type\":\"Initialized\"}":{".":{},"f:lastProbeTime":{},"f:lastTransitionTime":{},"f:status":{},"f:type":{}},"k:{\"type\":\"PodScheduled\"}":{"f:lastTransitionTime":{}},"k:{\"type\":\"Ready\"}":{".":{},"f:lastProbeTime":{},"f:lastTransitionTime":{},"f:status":{},"f:type":{}}},"f:containerStatuses":{},"f:hostIP":{},"f:phase":{},"f:podIP":{},"f:podIPs":{".":{},"k:{\"ip\":\"172.18.0.2\"}":{".":{},"f:ip":{}}},"f:startTime":{}}}}]},"spec":{"volumes":[{"name":"default-token-xnrgx","secret":{"secretName":"default-token-xnrgx","defaultMode":420}}],"containers":[{"name":"nginx","image":"nginx","resources":{},"volumeMounts":[{"name":"default-token-xnrgx","readOnly":true,"mountPath":"/var/run/secrets/kubernetes.io/serviceaccount"}],"terminationMessagePath":"/dev/termination-log","terminationMessagePolicy":"File","imagePullPolicy":"Always"}],"restartPolicy":"Always","terminationGracePeriodSeconds":30,"dnsPolicy":"ClusterFirst","serviceAccountName":"default","serviceAccount":"default","nodeName":"node2","securityContext":{},"affinity":{"nodeAffinity":{"requiredDuringSchedulingIgnoredDuringExecution":{"nodeSelectorTerms":[{"matchFields":[{"key":"metadata.name","operator":"In","values":["node2"]}]}]}}},"schedulerName":"default-scheduler","tolerations":[{"key":"edgefarm.applications","operator":"Exists","effect":"NoExecute"},{"key":"node.kubernetes.io/not-ready","operator":"Exists","effect":"NoExecute"},{"key":"node.kubernetes.io/unreachable","operator":"Exists","effect":"NoExecute"},{"key":"node.kubernetes.io/disk-pressure","operator":"Exists","effect":"NoSchedule"},{"key":"node.kubernetes.io/memory-pressure","operator":"Exists","effect":"NoSchedule"},{"key":"node.kubernetes.io/pid-pressure","operator":"Exists","effect":"NoSchedule"},{"key":"node.kubernetes.io/unschedulable","operator":"Exists","effect":"NoSchedule"}],"priority":0,"enableServiceLinks":true,"preemptionPolicy":"PreemptLowerPriority"},"status":{"phase":"Running","conditions":[{"type":"Initialized","status":"True","lastProbeTime":null,"lastTransitionTime":"2022-03-02T10:11:22Z"},{"type":"Ready","status":"True","lastProbeTime":null,"lastTransitionTime":"2022-03-02T10:11:42Z"},{"type":"PodScheduled","status":"True","lastProbeTime":null,"lastTransitionTime":null}],"hostIP":"172.17.0.6","podIP":"172.18.0.2","podIPs":[{"ip":"172.18.0.2"}],"startTime":"2022-03-02T10:11:12Z","containerStatuses":[{"name":"nginx","state":{"running":{"startedAt":"2022-03-02T10:11:41Z"}},"lastState":{},"ready":true,"restartCount":0,"image":"nginx:latest","imageID":"docker-pullable://nginx@sha256:6a9f18391bb80b75ce50472168ea38e4050f7f56aff8ad08cb4d38b43df1aab2","containerID":"docker://7d3acd00d77f3519482616629f9e1207b4b9a1cad70976dc91943a580df263a9","started":true}],"qosClass":"BestEffort"}}
I0302 11:50:03.514152 1808797 round_trippers.go:425] curl -k -v -XGET  -H "User-Agent: kubectl/v1.20.12 (linux/amd64) kubernetes/4bf2e32" -H "Accept: application/json, */*" 'https://0.0.0.0:30550/api/v1/namespaces/kubeedge/pods/nginx-9ph7q/log'
I0302 11:50:03.535168 1808797 round_trippers.go:445] GET https://0.0.0.0:30550/api/v1/namespaces/kubeedge/pods/nginx-9ph7q/log 500 Internal Server Error in 20 milliseconds
I0302 11:50:03.535191 1808797 round_trippers.go:451] Response Headers:
I0302 11:50:03.535201 1808797 round_trippers.go:454]     Cache-Control: no-cache, private
I0302 11:50:03.535210 1808797 round_trippers.go:454]     Content-Type: application/json
I0302 11:50:03.535I0302 11:50:03.501643 1808797 request.go:1107] Response Body: {"kind":"Pod","apiVersion":"v1","metadata":{"name":"nginx-9ph7q","generateName":"nginx-","namespace":"kubeedge","uid":"51a3f2fb-f9a0-4089-b914-0e4691bf3487","resourceVersion":"7674","creationTimestamp":"2022-03-02T10:11:02Z","labels":{"app":"nginx","controller-revision-hash":"5d477c5d4c","pod-template-generation":"1"},"ownerReferences":[{"apiVersion":"apps/v1","kind":"DaemonSet","name":"nginx","uid":"633fa88e-7678-4b96-8d5b-adeccd60adae","controller":true,"blockOwnerDeletion":true}],"managedFields":[{"manager":"k3s","operation":"Update","apiVersion":"v1","time":"2022-03-02T10:11:02Z","fieldsType":"FieldsV1","fieldsV1":{"f:metadata":{"f:generateName":{},"f:labels":{".":{},"f:app":{},"f:controller-revision-hash":{},"f:pod-template-generation":{}},"f:ownerReferences":{".":{},"k:{\"uid\":\"633fa88e-7678-4b96-8d5b-adeccd60adae\"}":{".":{},"f:apiVersion":{},"f:blockOwnerDeletion":{},"f:controller":{},"f:kind":{},"f:name":{},"f:uid":{}}}},"f:spec":{"f:affinity":{".":{},"f:nodeAffinity":{".":{},"f:requiredDuringSchedulingIgnoredDuringExecution":{".":{},"f:nodeSelectorTerms":{}}}},"f:containers":{"k:{\"name\":\"nginx\"}":{".":{},"f:image":{},"f:imagePullPolicy":{},"f:name":{},"f:resources":{},"f:terminationMessagePath":{},"f:terminationMessagePolicy":{}}},"f:dnsPolicy":{},"f:enableServiceLinks":{},"f:restartPolicy":{},"f:schedulerName":{},"f:securityContext":{},"f:terminationGracePeriodSeconds":{},"f:tolerations":{}}}},{"manager":"cloudcore","operation":"Update","apiVersion":"v1","time":"2022-03-02T10:11:42Z","fieldsType":"FieldsV1","fieldsV1":{"f:status":{"f:conditions":{"k:{\"type\":\"Initialized\"}":{".":{},"f:lastProbeTime":{},"f:lastTransitionTime":{},"f:status":{},"f:type":{}},"k:{\"type\":\"PodScheduled\"}":{"f:lastTransitionTime":{}},"k:{\"type\":\"Ready\"}":{".":{},"f:lastProbeTime":{},"f:lastTransitionTime":{},"f:status":{},"f:type":{}}},"f:containerStatuses":{},"f:hostIP":{},"f:phase":{},"f:podIP":{},"f:podIPs":{".":{},"k:{\"ip\":\"172.18.0.2\"}":{".":{},"f:ip":{}}},"f:startTime":{}}}}]},"spec":{"volumes":[{"name":"default-token-xnrgx","secret":{"secretName":"default-token-xnrgx","defaultMode":420}}],"containers":[{"name":"nginx","image":"nginx","resources":{},"volumeMounts":[{"name":"default-token-xnrgx","readOnly":true,"mountPath":"/var/run/secrets/kubernetes.io/serviceaccount"}],"terminationMessagePath":"/dev/termination-log","terminationMessagePolicy":"File","imagePullPolicy":"Always"}],"restartPolicy":"Always","terminationGracePeriodSeconds":30,"dnsPolicy":"ClusterFirst","serviceAccountName":"default","serviceAccount":"default","nodeName":"node2","securityContext":{},"affinity":{"nodeAffinity":{"requiredDuringSchedulingIgnoredDuringExecution":{"nodeSelectorTerms":[{"matchFields":[{"key":"metadata.name","operator":"In","values":["node2"]}]}]}}},"schedulerName":"default-scheduler","tolerations":[{"key":"edgefarm.applications","operator":"Exists","effect":"NoExecute"},{"key":"node.kubernetes.io/not-ready","operator":"Exists","effect":"NoExecute"},{"key":"node.kubernetes.io/unreachable","operator":"Exists","effect":"NoExecute"},{"key":"node.kubernetes.io/disk-pressure","operator":"Exists","effect":"NoSchedule"},{"key":"node.kubernetes.io/memory-pressure","operator":"Exists","effect":"NoSchedule"},{"key":"node.kubernetes.io/pid-pressure","operator":"Exists","effect":"NoSchedule"},{"key":"node.kubernetes.io/unschedulable","operator":"Exists","effect":"NoSchedule"}],"priority":0,"enableServiceLinks":true,"preemptionPolicy":"PreemptLowerPriority"},"status":{"phase":"Running","conditions":[{"type":"Initialized","status":"True","lastProbeTime":null,"lastTransitionTime":"2022-03-02T10:11:22Z"},{"type":"Ready","status":"True","lastProbeTime":null,"lastTransitionTime":"2022-03-02T10:11:42Z"},{"type":"PodScheduled","status":"True","lastProbeTime":null,"lastTransitionTime":null}],"hostIP":"172.17.0.6","podIP":"172.18.0.2","podIPs":[{"ip":"172.18.0.2"}],"startTime":"2022-03-02T10:11:12Z","containerStatuses":[{"name":"nginx","state":{"running":{"startedAt":"2022-03-02T10:11:41Z"}},"lastState":{},"ready":true,"restartCount":0,"image":"nginx:latest","imageID":"docker-pullable://nginx@sha256:6a9f18391bb80b75ce50472168ea38e4050f7f56aff8ad08cb4d38b43df1aab2","containerID":"docker://7d3acd00d77f3519482616629f9e1207b4b9a1cad70976dc91943a580df263a9","started":true}],"qosClass":"BestEffort"}}219 1808797 round_trippers.go:454]     Date: Wed, 02 Mar 2022 10:50:03 GMT
I0302 11:50:03.535228 1808797 round_trippers.go:454]     Content-Length: 199
I0302 11:50:03.535285 1808797 request.go:1107] Response Body: {"kind":"Status","apiVersion":"v1","metadata":{},"status":"Failure","message":"Get \"https://node2:10351/containerLogs/kubeedge/nginx-9ph7q/nginx\": dial tcp: lookup node2: no such host","code":500}
I0302 11:50:03.535806 1808797 helpers.go:216] server response object: [{
  "metadata": {},
  "status": "Failure",
  "message": "Get \"https://node2:10351/containerLogs/kubeedge/nginx-9ph7q/nginx\": dial tcp: lookup node2: no such host",
  "code": 500
}]
F0302 11:50:03.535840 1808797 helpers.go:115] Error from server: Get "https://node2:10351/containerLogs/kubeedge/nginx-9ph7q/nginx": dial tcp: lookup node2: no such host

And this is the output running RKE1:

$ kubectl -n kubeedge logs nginx-klpj4 -v9           
I0302 11:52:38.976947 1818917 loader.go:379] Config loaded from file:  /home/armin/Downloads/edgefarm-armin.yaml
I0302 11:52:38.981089 1818917 round_trippers.go:425] curl -k -v -XGET  -H "Accept: application/json, */*" -H "User-Agent: kubectl/v1.20.12 (linux/amd64) kubernetes/4bf2e32" -H "Authorization: Bearer <masked>" 'https://94.130.99.6:6443/api/v1/namespaces/kubeedge/pods/nginx-klpj4'
I0302 11:52:39.051397 1818917 round_trippers.go:445] GET https://94.130.99.6:6443/api/v1/namespaces/kubeedge/pods/nginx-klpj4 200 OK in 70 milliseconds
I0302 11:52:39.051422 1818917 round_trippers.go:451] Response Headers:
I0302 11:52:39.051427 1818917 round_trippers.go:454]     Date: Wed, 02 Mar 2022 10:52:39 GMT
I0302 11:52:39.051431 1818917 round_trippers.go:454]     Audit-Id: 3899782c-d39f-4f41-a77c-afc9e5ca2fdc
I0302 11:52:39.051436 1818917 round_trippers.go:454]     Cache-Control: no-cache, private
I0302 11:52:39.051444 1818917 round_trippers.go:454]     Content-Type: application/json
I0302 11:52:39.051450 1818917 round_trippers.go:454]     X-Kubernetes-Pf-Flowschema-Uid: 804f5f7d-593b-48d3-a029-ab469d6b36e0
I0302 11:52:39.051455 1818917 round_trippers.go:454]     X-Kubernetes-Pf-Prioritylevel-Uid: 53e1fd90-cfd2-4ec8-9a13-d56c8507126a
I0302 11:52:39.051564 1818917 request.go:1107] Response Body: {"kind":"Pod","apiVersion":"v1","metadata":{"name":"nginx-klpj4","generateName":"nginx-","namespace":"kubeedge","uid":"630b7501-ed87-41ce-9690-851c20c8d50d","resourceVersion":"355694","creationTimestamp":"2022-03-01T11:33:03Z","labels":{"app":"nginx","controller-revision-hash":"5d477c5d4c","pod-template-generation":"1"},"ownerReferences":[{"apiVersion":"apps/v1","kind":"DaemonSet","name":"nginx","uid":"9eebf0d8-a283-4280-88ee-266927c864d7","controller":true,"blockOwnerDeletion":true}],"managedFields":[{"manager":"kube-controller-manager","operation":"Update","apiVersion":"v1","time":"2022-03-01T22:19:24Z","fieldsType":"FieldsV1","fieldsV1":{"f:metadata":{"f:generateName":{},"f:labels":{".":{},"f:app":{},"f:controller-revision-hash":{},"f:pod-template-generation":{}},"f:ownerReferences":{".":{},"k:{\"uid\":\"9eebf0d8-a283-4280-88ee-266927c864d7\"}":{".":{},"f:apiVersion":{},"f:blockOwnerDeletion":{},"f:controller":{},"f:kind":{},"f:name":{},"f:uid":{}}}},"f:spec":{"f:affinity":{".":{},"f:nodeAffinity":{".":{},"f:requiredDuringSchedulingIgnoredDuringExecution":{".":{},"f:nodeSelectorTerms":{}}}},"f:containers":{"k:{\"name\":\"nginx\"}":{".":{},"f:image":{},"f:imagePullPolicy":{},"f:name":{},"f:resources":{},"f:terminationMessagePath":{},"f:terminationMessagePolicy":{}}},"f:dnsPolicy":{},"f:enableServiceLinks":{},"f:restartPolicy":{},"f:schedulerName":{},"f:securityContext":{},"f:terminationGracePeriodSeconds":{},"f:tolerations":{}}}},{"manager":"cloudcore","operation":"Update","apiVersion":"v1","time":"2022-03-02T06:26:47Z","fieldsType":"FieldsV1","fieldsV1":{"f:status":{"f:conditions":{"k:{\"type\":\"Initialized\"}":{".":{},"f:lastProbeTime":{},"f:lastTransitionTime":{},"f:status":{},"f:type":{}},"k:{\"type\":\"PodScheduled\"}":{"f:lastTransitionTime":{}},"k:{\"type\":\"Ready\"}":{".":{},"f:lastProbeTime":{},"f:lastTransitionTime":{},"f:status":{},"f:type":{}}},"f:containerStatuses":{},"f:hostIP":{},"f:phase":{},"f:podIP":{},"f:podIPs":{".":{},"k:{\"ip\":\"172.18.0.2\"}":{".":{},"f:ip":{}}},"f:startTime":{}}}}]},"spec":{"volumes":[{"name":"kube-api-access-8g455","projected":{"sources":[{"serviceAccountToken":{"expirationSeconds":3607,"path":"token"}},{"configMap":{"name":"kube-root-ca.crt","items":[{"key":"ca.crt","path":"ca.crt"}]}},{"downwardAPI":{"items":[{"path":"namespace","fieldRef":{"apiVersion":"v1","fieldPath":"metadata.namespace"}}]}}],"defaultMode":420}}],"containers":[{"name":"nginx","image":"nginx","resources":{},"volumeMounts":[{"name":"kube-api-access-8g455","readOnly":true,"mountPath":"/var/run/secrets/kubernetes.io/serviceaccount"}],"terminationMessagePath":"/dev/termination-log","terminationMessagePolicy":"File","imagePullPolicy":"Always"}],"restartPolicy":"Always","terminationGracePeriodSeconds":30,"dnsPolicy":"ClusterFirst","serviceAccountName":"default","serviceAccount":"default","nodeName":"node3","securityContext":{},"affinity":{"nodeAffinity":{"requiredDuringSchedulingIgnoredDuringExecution":{"nodeSelectorTerms":[{"matchFields":[{"key":"metadata.name","operator":"In","values":["node3"]}]}]}}},"schedulerName":"default-scheduler","tolerations":[{"key":"edgefarm.applications","operator":"Exists","effect":"NoExecute"},{"key":"node.kubernetes.io/not-ready","operator":"Exists","effect":"NoExecute"},{"key":"node.kubernetes.io/unreachable","operator":"Exists","effect":"NoExecute"},{"key":"node.kubernetes.io/disk-pressure","operator":"Exists","effect":"NoSchedule"},{"key":"node.kubernetes.io/memory-pressure","operator":"Exists","effect":"NoSchedule"},{"key":"node.kubernetes.io/pid-pressure","operator":"Exists","effect":"NoSchedule"},{"key":"node.kubernetes.io/unschedulable","operator":"Exists","effect":"NoSchedule"}],"priority":0,"enableServiceLinks":true,"preemptionPolicy":"PreemptLowerPriority"},"status":{"phase":"Running","conditions":[{"type":"Initialized","status":"True","lastProbeTime":null,"lastTransitionTime":"2022-03-01T11:33:23Z"},{"type":"Ready","status":"True","lastProbeTime":null,"lastTransitionTime":"2022-03-02T06:26:47Z"},{"type":"PodScheduled","status":"True","lastProbeTime":null,"lastTransitionTime":null}],"hostIP":"172.17.0.4","podIP":"172.18.0.2","podIPs":[{"ip":"172.18.0.2"}],"startTime":"2022-03-01T11:33:13Z","containerStatuses":[{"name":"nginx","state":{"running":{"startedAt":"2022-03-01T11:34:41Z"}},"lastState":{},"ready":true,"restartCount":0,"image":"nginx:latest","imageID":"docker-pullable://nginx@sha256:f7cd562e1b59e7868facf01c115515d694eb3d9ddd485120b325932937bf8793","containerID":"docker://62c178395a80e3548935be15d3268be468dddde6ba4d602ac16b4cb50ecb36bc","started":true}],"qosClass":"BestEffort"}}
I0302 11:52:39.059233 1818917 round_trippers.go:425] curl -k -v -XGET  -H "Authorization: Bearer <masked>" -H "Accept: application/json, */*" -H "User-Agent: kubectl/v1.20.12 (linux/amd64) kubernetes/4bf2e32" 'https://94.130.99.6:6443/api/v1/namespaces/kubeedge/pods/nginx-klpj4/log'
I0302 11:52:39.186582 1818917 round_trippers.go:445] GET https://94.130.99.6:6443/api/v1/namespaces/kubeedge/pods/nginx-klpj4/log 200 OK in 127 milliseconds
I0302 11:52:39.186628 1818917 round_trippers.go:451] Response Headers:
I0302 11:52:39.186641 1818917 round_trippers.go:454]     Audit-Id: 6cfc0aef-94df-416e-b887-70c82a72a0ab
I0302 11:52:39.186654 1818917 round_trippers.go:454]     Cache-Control: no-cache, private
I0302 11:52:39.186667 1818917 round_trippers.go:454]     Content-Type: text/plain
I0302 11:52:39.186680 1818917 round_trippers.go:454]     Date: Wed, 02 Mar 2022 10:52:39 GMT
/docker-entrypoint.sh: /docker-entrypoint.d/ is not empty, will attempt to perform configuration
/docker-entrypoint.sh: Looking for shell scripts in /docker-entrypoint.d/
/docker-entrypoint.sh: Launching /docker-entrypoint.d/10-listen-on-ipv6-by-default.sh
10-listen-on-ipv6-by-default.sh: info: Getting the checksum of /etc/nginx/conf.d/default.conf
10-listen-on-ipv6-by-default.sh: info: Enabled listen on IPv6 in /etc/nginx/conf.d/default.conf
/docker-entrypoint.sh: Launching /docker-entrypoint.d/20-envsubst-on-templates.sh
/docker-entrypoint.sh: Launching /docker-entrypoint.d/30-tune-worker-processes.sh
/docker-entrypoint.sh: Configuration complete; ready for start up
2022/03/01 11:34:41 [notice] 1#1: using the "epoll" event method
2022/03/01 11:34:41 [notice] 1#1: nginx/1.21.6
2022/03/01 11:34:41 [notice] 1#1: built by gcc 10.2.1 20210110 (Debian 10.2.1-6) 
2022/03/01 11:34:41 [notice] 1#1: OS: Linux 5.8.18-050818-generic
2022/03/01 11:34:41 [notice] 1#1: getrlimit(RLIMIT_NOFILE): 1048576:1048576
2022/03/01 11:34:41 [notice] 1#1: start worker processes
2022/03/01 11:34:41 [notice] 1#1: start worker process 30
2022/03/01 11:34:41 [notice] 1#1: start worker process 31
2022/03/01 11:34:41 [notice] 1#1: start worker process 32
2022/03/01 11:34:41 [notice] 1#1: start worker process 33
2022/03/01 11:34:41 [notice] 1#1: start worker process 34
2022/03/01 11:34:41 [notice] 1#1: start worker process 35
2022/03/01 11:34:41 [notice] 1#1: start worker process 36
2022/03/01 11:34:41 [notice] 1#1: start worker process 37
2022/03/01 11:34:41 [notice] 1#1: start worker process 38
2022/03/01 11:34:41 [notice] 1#1: start worker process 39
2022/03/01 11:34:41 [notice] 1#1: start worker process 40
2022/03/01 11:34:41 [notice] 1#1: start worker process 41

How to setup the environment

Make sure you have k3d and mkcert installed.

These are the steps to start up the environment locally. It starts a new cluster called k3d-edgefarm-core and instantiates two virtual docker devices.

$ git clone https://github.com/edgefarm/edgefarm.core.git && cd edgefarm.core/dev
$ devspace run init
$ devspace run activate
$ devspace deploy
$ devspace run instantiate-nodes

Next apply this demo application:

$ cat <<EOF | kubectl apply -f -
apiVersion: apps/v1
kind: DaemonSet
metadata:
  name: nginx
spec:
  selector:
    matchLabels:
      app: nginx
  template:
    metadata:
      labels:
        app: nginx
    spec:
      containers:
        - name: nginx
          image: nginx
      affinity:
        nodeAffinity:
          requiredDuringSchedulingIgnoredDuringExecution:
            nodeSelectorTerms:
              - matchExpressions:
                  - key: node-role.kubernetes.io/edge
                    operator: Exists
                  - key: node-role.kubernetes.io/agent
                    operator: Exists
      tolerations:
        - effect: NoExecute
          key: edgefarm.applications
          operator: Exists
EOF

Now you can play around with the logs feature (see section above).

What am i missing here?

[iwilltry42]

Hey @siredmar , thanks for starting this discussion!
That's a lot of text, but also a well done question 👍

So the strange about this is that it tries to get the logs directly from the node node1 and does not try to contact the api server.

I actually think that the final reply (FATAL log) and the informational output are what is returned by the Kubeedge component which fails to get the logs directly from the node. Kubectl itself seems to only connect to the API Server according to the GET log entries 🤔

Possibly that lookup (dial tcp: lookup node2: no such host), because the nodes are not in the same docker network? 🤔
-> 1. Create some docker network (docker network create mynet), 2. make k3d use that network (config network: mynet), 3. create your edge nodes in that network (docker run --net mynet ...), maybe that helps.

I didn't play with it yet, so that's just a guess.

EDIT: Unfortunately, the devspace commands didn't work for me and happened to modify an existing non-toy cluster 😖
Let me get this straight before trying again...

EDIT 2: This part of the devspace config seems to be a bit wrong: https://github.com/edgefarm/devspace.base/blob/main/environments/k3d/devspace.yaml#L25-L32
--> You create the cluster before ensuring that the registry exists, causing it to fail if it doesn't.. but that doesn't stop the script, so it just continues to do its job and deploy stuff, etc.

EDIT 3: There's too much for me to fix first in the devspace setup, so I cannot test it right now...