search

solo-io / wasm

Web Assembly tools and SDKs for extending cloud-native infrastructure
Apache License 2.0
306 stars 40 forks source link

Error adding/updating listener(s) virtualInbound: Invalid path: /var/local/lib/wasme-cache/0295d929353976266ab721389ec859b2fe012d63ce2e58815469ab85c123b510 #251

Closed tanjunchen closed 3 years ago

tanjunchen commented 3 years ago

Describe the bug A clear and concise description of what the bug is.

I was using the latest version of wasm, deployed istio 1.9.1, and found that istio-proxy failed.

[root@mesh-10-20-11-190 wasme]# kubectl get pods -n istio-system 
NAME                                    READY   STATUS    RESTARTS   AGE
istio-egressgateway-5888c588c8-zqb8v    1/1     Running   0          29m
istio-ingressgateway-75fddcf865-cbmnx   1/1     Running   0          29m
istiod-5f89f959fd-72gpd                 1/1     Running   0          29m
[root@mesh-10-20-11-190 wasme]# kubectl get pods -n bookinfo
NAME                              READY   STATUS    RESTARTS   AGE
details-v1-5f449bdbb9-kfgrq       2/2     Running   0          30m
details-v1-7c4fc4cfc-5g729        1/2     Running   0          14m
productpage-v1-6f9df695b7-rl9j7   2/2     Running   0          30m
productpage-v1-c9b48dd87-mtqgv    1/2     Running   0          13m
ratings-v1-857bb87c57-fpvrf       2/2     Running   0          30m
ratings-v1-9cd74d5d5-7h9g6        1/2     Running   0          13m
reviews-v1-68f9c47f69-6sfq6       2/2     Running   0          30m
reviews-v1-779c4b8b7c-l4t9h       1/2     Running   0          13m
reviews-v2-5d56c488f5-t2k5b       2/2     Running   0          30m
reviews-v2-c6d6bb59f-5d7nv        1/2     Running   0          13m
reviews-v3-56997446d9-bp6m5       1/2     Running   0          13m
reviews-v3-869ff44845-68jvx       2/2     Running   0          30m

the logs of the productpage-v1-c9b48dd87-mtqgv/istio-proxy

kubectl logs -f productpage-v1-c9b48dd87-mtqgv -c istio-proxy -n bookinfo
2021-04-02T08:07:56.825402Z warn    Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 1 successful, 0 rejected; lds updates: 0 successful, 1 rejected
2021-04-02T08:07:58.833325Z warn    Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 1 successful, 0 rejected; lds updates: 0 successful, 1 rejected
2021-04-02T08:08:00.824948Z warn    Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 1 successful, 0 rejected; lds updates: 0 successful, 1 rejected
2021-04-02T08:08:02.824990Z warn    Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 1 successful, 0 rejected; lds updates: 0 successful, 1 rejected
2021-04-02T08:08:04.824860Z warn    Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 1 successful, 0 rejected; lds updates: 0 successful, 1 rejected
2021-04-02T08:08:06.825076Z warn    Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 1 successful, 0 rejected; lds updates: 0 successful, 1 rejected

the logs of istiod

2021-04-02T07:57:13.177495Z info    ads ADS: new connection for node:sidecar~192.168.100.237~reviews-v3-56997446d9-bp6m5.bookinfo~bookinfo.svc.cluster.local-20
2021-04-02T07:57:13.179374Z info    ads CDS: PUSH for node:reviews-v3-56997446d9-bp6m5.bookinfo resources:23 size:19.9kB
2021-04-02T07:57:13.372672Z info    ads EDS: PUSH for node:reviews-v3-56997446d9-bp6m5.bookinfo resources:19 size:4.8kB empty:0 cached:19/19
2021-04-02T07:57:14.831700Z info    ads LDS: PUSH for node:reviews-v3-56997446d9-bp6m5.bookinfo resources:17 size:75.7kB
2021-04-02T07:57:14.951051Z info    ads RDS: PUSH for node:reviews-v3-56997446d9-bp6m5.bookinfo resources:6 size:6.9kB
2021-04-02T07:57:14.951105Z warn    ads ADS:LDS: ACK ERROR sidecar~192.168.100.237~reviews-v3-56997446d9-bp6m5.bookinfo~bookinfo.svc.cluster.local-20 Internal:Error adding/updating listener(s) virtualInbound: Invalid path: /var/local/lib/wasme-cache/0295d929353976266ab721389ec859b2fe012d63ce2e58815469ab85c123b510

2021-04-02T08:06:22.587415Z info    ads ADS: "192.168.100.196:33878" router~192.168.100.196~istio-ingressgateway-75fddcf865-cbmnx.istio-system~istio-system.svc.cluster.local-1 terminated rpc error: code = Canceled desc = context canceled
2021-04-02T08:06:22.869046Z info    ads ADS: new connection for node:router~192.168.100.196~istio-ingressgateway-75fddcf865-cbmnx.istio-system~istio-system.svc.cluster.local-21
2021-04-02T08:06:22.870445Z info    ads CDS: PUSH for node:istio-ingressgateway-75fddcf865-cbmnx.istio-system resources:20 size:19.3kB
2021-04-02T08:06:22.870702Z info    ads EDS: PUSH for node:istio-ingressgateway-75fddcf865-cbmnx.istio-system resources:19 size:4.8kB empty:0 cached:19/19
2021-04-02T08:06:22.870957Z info    ads LDS: PUSH for node:istio-ingressgateway-75fddcf865-cbmnx.istio-system resources:0 size:0B
2021-04-02T08:06:54.433424Z info    ads ADS: "192.168.100.217:44352" router~192.168.100.217~istio-egressgateway-5888c588c8-zqb8v.istio-system~istio-system.svc.cluster.local-2 terminated rpc error: code = Canceled desc = context canceled
2021-04-02T08:06:54.738408Z info    ads ADS: new connection for node:router~192.168.100.217~istio-egressgateway-5888c588c8-zqb8v.istio-system~istio-system.svc.cluster.local-22
2021-04-02T08:06:54.740112Z info    ads CDS: PUSH for node:istio-egressgateway-5888c588c8-zqb8v.istio-system resources:20 size:19.3kB
2021-04-02T08:06:54.740209Z info    ads EDS: PUSH for node:istio-egressgateway-5888c588c8-zqb8v.istio-system resources:19 size:4.8kB empty:0 cached:19/19
2021-04-02T08:06:54.740474Z info    ads LDS: PUSH for node:istio-egressgateway-5888c588c8-zqb8v.istio-system resources:0 size:0B
2021-04-02T08:08:15.139532Z info    ads ADS: "192.168.100.232:40788" sidecar~192.168.100.232~reviews-v1-68f9c47f69-6sfq6.bookinfo~bookinfo.svc.cluster.local-5 terminated rpc error: code = Canceled desc = context canceled
2021-04-02T08:08:15.217412Z info    ads ADS: new connection for node:sidecar~192.168.100.232~reviews-v1-68f9c47f69-6sfq6.bookinfo~bookinfo.svc.cluster.local-23
2021-04-02T08:08:15.218902Z info    ads CDS: PUSH for node:reviews-v1-68f9c47f69-6sfq6.bookinfo resources:23 size:19.9kB
2021-04-02T08:08:15.219006Z info    ads EDS: PUSH for node:reviews-v1-68f9c47f69-6sfq6.bookinfo resources:19 size:4.8kB empty:0 cached:19/19
2021-04-02T08:08:15.223046Z info    ads LDS: PUSH for node:reviews-v1-68f9c47f69-6sfq6.bookinfo resources:17 size:75.7kB
2021-04-02T08:08:15.223602Z info    ads RDS: PUSH for node:reviews-v1-68f9c47f69-6sfq6.bookinfo resources:6 size:6.9kB
2021-04-02T08:08:15.260989Z warn    ads ADS:LDS: ACK ERROR sidecar~192.168.100.232~reviews-v1-68f9c47f69-6sfq6.bookinfo~bookinfo.svc.cluster.local-23 Internal:Error adding/updating listener(s) virtualInbound: Invalid path: /var/local/lib/wasme-cache/0295d929353976266ab721389ec859b2fe012d63ce2e58815469ab85c123b510

2021-04-02T08:08:36.232366Z info    ads ADS: "192.168.100.194:41630" sidecar~192.168.100.194~details-v1-5f449bdbb9-kfgrq.bookinfo~bookinfo.svc.cluster.local-3 terminated rpc error: code = Canceled desc = context canceled
2021-04-02T08:08:36.270821Z info    ads ADS: new connection for node:sidecar~192.168.100.194~details-v1-5f449bdbb9-kfgrq.bookinfo~bookinfo.svc.cluster.local-24
2021-04-02T08:08:36.272662Z info    ads CDS: PUSH for node:details-v1-5f449bdbb9-kfgrq.bookinfo resources:23 size:19.9kB
2021-04-02T08:08:36.272821Z info    ads EDS: PUSH for node:details-v1-5f449bdbb9-kfgrq.bookinfo resources:19 size:4.8kB empty:0 cached:19/19
2021-04-02T08:08:36.275199Z info    ads LDS: PUSH for node:details-v1-5f449bdbb9-kfgrq.bookinfo resources:17 size:75.7kB
2021-04-02T08:08:36.276258Z info    ads RDS: PUSH for node:details-v1-5f449bdbb9-kfgrq.bookinfo resources:6 size:6.9kB
2021-04-02T08:08:36.309279Z warn    ads ADS:LDS: ACK ERROR sidecar~192.168.100.194~details-v1-5f449bdbb9-kfgrq.bookinfo~bookinfo.svc.cluster.local-24 Internal:Error adding/updating listener(s) virtualInbound: Invalid path: /var/local/lib/wasme-cache/0295d929353976266ab721389ec859b2fe012d63ce2e58815469ab85c123b510

2021-04-02T08:08:42.377165Z info    ads ADS: "192.168.100.218:58686" sidecar~192.168.100.218~productpage-v1-6f9df695b7-rl9j7.bookinfo~bookinfo.svc.cluster.local-8 terminated rpc error: code = Canceled desc = context canceled
2021-04-02T08:08:42.749388Z info    ads ADS: new connection for node:sidecar~192.168.100.218~productpage-v1-6f9df695b7-rl9j7.bookinfo~bookinfo.svc.cluster.local-25
2021-04-02T08:08:42.751649Z info    ads CDS: PUSH for node:productpage-v1-6f9df695b7-rl9j7.bookinfo resources:23 size:19.9kB
2021-04-02T08:08:42.751921Z info    ads EDS: PUSH for node:productpage-v1-6f9df695b7-rl9j7.bookinfo resources:19 size:4.8kB empty:0 cached:19/19
2021-04-02T08:08:42.762457Z info    ads LDS: PUSH for node:productpage-v1-6f9df695b7-rl9j7.bookinfo resources:17 size:75.7kB
2021-04-02T08:08:42.763143Z info    ads RDS: PUSH for node:productpage-v1-6f9df695b7-rl9j7.bookinfo resources:6 size:6.9kB
2021-04-02T08:08:42.805280Z warn    ads ADS:LDS: ACK ERROR sidecar~192.168.100.218~productpage-v1-6f9df695b7-rl9j7.bookinfo~bookinfo.svc.cluster.local-25 Internal:Error adding/updating listener(s) virtualInbound: Invalid path: /var/local/lib/wasme-cache/0295d929353976266ab721389ec859b2fe012d63ce2e58815469ab85c123b510

the envoyfliter of productpage-v1-myfilter

apiVersion: networking.istio.io/v1alpha3
kind: EnvoyFilter
metadata:
  creationTimestamp: "2021-04-02T07:53:04Z"
  generation: 1
  name: productpage-v1-myfilter
  namespace: bookinfo
  resourceVersion: "7471971"
  selfLink: /apis/networking.istio.io/v1alpha3/namespaces/bookinfo/envoyfilters/productpage-v1-myfilter
  uid: 0ecf8a7d-ec8a-42a0-a1c8-0a410b7eb529
spec:
  configPatches:
  - applyTo: HTTP_FILTER
    match:
      context: SIDECAR_INBOUND
      listener:
        filterChain:
          filter:
            name: envoy.http_connection_manager
            subFilter:
              name: envoy.router
    patch:
      operation: INSERT_BEFORE
      value:
        name: envoy.filters.http.wasm
        typedConfig:
          '@type': type.googleapis.com/udpa.type.v1.TypedStruct
          typeUrl: type.googleapis.com/envoy.extensions.filters.http.wasm.v3.Wasm
          value:
            config:
              configuration:
                '@type': type.googleapis.com/google.protobuf.StringValue
                value: world
              name: myfilter
              rootId: add_header
              vmConfig:
                code:
                  local:
                    filename: /var/local/lib/wasme-cache/0295d929353976266ab721389ec859b2fe012d63ce2e58815469ab85c123b510
                runtime: envoy.wasm.runtime.v8
                vmId: myfilter
  workloadSelector:
    labels:
      app: productpage
      version: v1

To Reproduce Steps to reproduce the behavior:

  1. kube apply '...'
  2. curl '....'
  3. See error

Expected behavior A clear and concise description of what you expected to happen.

We can use the wasme function correctly according to https://docs.solo.io/web-assembly-hub/latest/tutorial_code/deploy_tutorials/deploying_with_istio/

Additional context Add any other context about the problem here, e.g.

istio 1.9.1

tanjunchen commented 3 years ago

for this error 

 Error adding/updating listener(s) virtualInbound: Invalid path: /var/local/lib/wasme-cache/0295d929353976266ab721389ec859b2fe012d63ce2e58815469ab85c123b510

i found that 0295d929353976266ab721389ec859b2fe012d63ce2e58815469ab85c123b510 is not found in /var/local/lib/wasme-cache. You can exec wasme deploy and then wasme undeploy, which should reproduce the problem. Or change a file and recompile, you will find that the image has changed, but the files in the /var/local/lib/wasme-cache directory seem to have not changed. It may be related to configmap、daemon in wasme.

INFO[0000] cache namespace already exists                cache=wasme-cache.wasme image="quay.io/solo-io/wasme:0.0.33"
INFO[0000] cache configmap already exists                cache=wasme-cache.wasme image="quay.io/solo-io/wasme:0.0.33"
INFO[0000] cache service account already exists          cache=wasme-cache.wasme image="quay.io/solo-io/wasme:0.0.33"
INFO[0000] cache role updated                            cache=wasme-cache.wasme image="quay.io/solo-io/wasme:0.0.33"
INFO[0000] cache rolebinding updated                     cache=wasme-cache.wasme image="quay.io/solo-io/wasme:0.0.33"
INFO[0000] cache daemonset updated                       cache=wasme-cache.wasme image="quay.io/solo-io/wasme:0.0.33"
INFO[0007] image is already cached                       cache="{wasme-cache wasme}" image="webassemblyhub.io/tanjunchen20/add-header:v0.1"

i guess there is a bug in following process.

it can be resolved by delete the po in wasme namespace. laughing

we need to check the SHA of image not the image name. see https://github.com/solo-io/wasm/blob/master/tools/wasme/cli/pkg/deploy/istio/istio_provider.go#L234