search

acorn-io / runtime

A simple application deployment framework built on Kubernetes
https://docs.acorn.io/
Apache License 2.0
1.13k stars 100 forks source link

acorn install fail on AKS #670

Closed meldafrawi closed 2 years ago

meldafrawi commented 2 years ago

Steps to reproduce:

  1. Create AKS cluster
  2. install acorn
  3. run acorn check

logs:

NAME                  PASSED    MESSAGE
RBAC                  true      User can create namespaces
NodesReady            true      All nodes are ready
DefaultStorageClass   true      Found default storage class default
IngressCapability     false     Ingress not ready (test timed out)
Exec                  true      Successfully executed command in container replica
Error: 1 checks failed
meldafrawi commented 2 years ago

Was able to bass the checks by deploying nginx ingress controller to the default namespace

if nginx ingress deployed to different namespace, the issue still exists.

  1. helm repo add nginx-stable https://helm.nginx.com/stable
  2. helm repo update
  3. helm install --set 'controller.setAsDefaultIngress=true' --set controller.service.annotations."service\.beta\.kubernetes\.io/azure-load-balancer-health-probe-request-path"=/healthz nginx-ingress nginx-stable/nginx-ingress
  4. acorn install --ingress-class-name nginx

logs:

  ✔  Running Pre-install Checks                                                                                                                                                                                    
  ✔  Installing ClusterRoles                                                                                                                                                                                       
  ✔  Installing APIServer and Controller (image ghcr.io/acorn-io/acorn:v0.2.0)                                                                                                                                     
  ✔  Waiting for controller deployment to be available                                                                                                                                                             
  ✔  Waiting for API server deployment to be available                                                                                                                                                             
  ✔  Installation done

However when trying to run the following Acornfile:

containers: {
    app: {
        image: "redis:alpine"
    }
}

acorn was not able to download the image from the registry. acorn apps

output:

NAME            IMAGE          HEALTHY   UP-TO-DATE   CREATED   ENDPOINTS   MESSAGE
hidden-sunset   73399bb43852   0/1       1            19s ago               [containers: app ImagePullBackOff: Back-off pulling image "127.0.0.1:30879/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a"; hidden-sunset is not ready]
cjellick commented 2 years ago

@iwilltry42 thoughts on this? The fact that it only works if installed in the default namespace is odd.

@meldafrawi what version of k8s is this?

meldafrawi commented 2 years ago

k8s version: 1.24.3

iwilltry42 commented 2 years ago

Hi @meldafrawi , in my tests, the ingresscapability check tends to timeout fairly often, since ingress-nginx seems to be fairly slow to populate the ingress address field. That's why my PR over here increases the timeout to 1 minute.

This still seems odd. Can you verify that it works in general by creating any Ingress object while nginx is deployed in another namespace? What we're looking for is that the ADDRESS field is populated and you can check that just with kubectl get ingress myingress. It may take a while.

Here's a simple example for testing:

apiVersion: networking.k8s.io/v1
kind: Ingress
metadata:
  name: myingress
  labels:
    name: myingress
spec:
  ingressClassName: nginx
  rules:
  - host: myapp.local.on-acorn.io
    http:
      paths:
      - pathType: Prefix
        path: "/"
        backend:
          service:
            name: myapp
            port: 
              number: 80

---
apiVersion: v1
kind: Service
metadata:
  name: myapp
spec:
  selector:
    app: myapp
  ports:
  - port: 80
    targetPort: 80

---
apiVersion: apps/v1
kind: Deployment
metadata:
  name: myapp
  labels:
    app: myapp
spec:
  selector:
    matchLabels:
      app: myapp
  template:
    metadata:
      labels:
        app: myapp
    spec:
      containers:
      - name: myapp
        image: nginx
        resources:
          limits:
            memory: "128Mi"
            cpu: "500m"
        ports:
        - containerPort: 80
meldafrawi commented 2 years ago

@iwilltry42

Yes, ADDRESS field is populated using the example you provided.

kubectl get ingress -A 
NAMESPACE   NAME        CLASS   HOSTS                     ADDRESS          PORTS   AGE
default     myingress   nginx   myapp.local.on-acorn.io   52.xxx.xxx.xxx   80      7s
iwilltry42 commented 2 years ago

Then I guess it should work with the increased timeout :+1:

meldafrawi commented 2 years ago

The issue now is that after intalling nginx as ingress controller, and install acorn on the AKS cluster.

I've tried to run a simple acorn app. I was able to build and list images on the local registry.

### acorn build  logs 
127.0.0.1 - - [12/Sep/2022:16:55:34 +0000] "HEAD /v2/acorn/acorn/blobs/sha256:7402bc4c98a0e78307c5d13c4c87ab3fd18e238b6752181d6b7669855c0845c4 HTTP/1.1" 200 0 "" "buildkit/v0.10"
time="2022-09-12T16:55:34.156299197Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5000" http.request.id=2cea1964-66ca-47c2-94b3-3303f4259afb http.request.method=HEAD http.request.remoteaddr="127.0.0.1:38570" http.request.uri="/v2/acorn/acorn/blobs/sha256:7402bc4c98a0e78307c5d13c4c87ab3fd18e238b6752181d6b7669855c0845c4" http.request.useragent="buildkit/v0.10" http.response.contenttype="application/octet-stream" http.response.duration=1.646245ms http.response.status=200 http.response.written=0 
time="2022-09-12T16:55:34.157415827Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5000" http.request.id=da437625-6ae1-4acc-bd73-9ec0443691d3 http.request.method=HEAD http.request.remoteaddr="127.0.0.1:38572" http.request.uri="/v2/acorn/acorn/blobs/sha256:213ec9aee27d8be045c6a92b7eac22c9a64b44558193775a1a7f626352392b49" http.request.useragent="buildkit/v0.10" http.response.contenttype="application/octet-stream" http.response.duration=2.21736ms http.response.status=200 http.response.written=0 
127.0.0.1 - - [12/Sep/2022:16:55:34 +0000] "HEAD /v2/acorn/acorn/blobs/sha256:213ec9aee27d8be045c6a92b7eac22c9a64b44558193775a1a7f626352392b49 HTTP/1.1" 200 0 "" "buildkit/v0.10"
127.0.0.1 - - [12/Sep/2022:16:55:34 +0000] "HEAD /v2/acorn/acorn/blobs/sha256:6d80de393db7bb6d3178742ef3dc3e905253dd47165fb9eeb53a50993c699262 HTTP/1.1" 200 0 "" "buildkit/v0.10"
time="2022-09-12T16:55:34.160426308Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5000" http.request.id=05e0eb69-8829-494c-94d9-274d32c46018 http.request.method=HEAD http.request.remoteaddr="127.0.0.1:38574" http.request.uri="/v2/acorn/acorn/blobs/sha256:6d80de393db7bb6d3178742ef3dc3e905253dd47165fb9eeb53a50993c699262" http.request.useragent="buildkit/v0.10" http.response.contenttype="application/octet-stream" http.response.duration=2.887478ms http.response.status=200 http.response.written=0 
time="2022-09-12T16:55:34.165141135Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5000" http.request.id=5815d583-a7a3-448f-b76d-0d954cf87e84 http.request.method=HEAD http.request.remoteaddr="127.0.0.1:38578" http.request.uri="/v2/acorn/acorn/blobs/sha256:8dbffc478db1b3dee9f43a7d5cfc7d94727286fb59cd0adb6902707b7a3c5682" http.request.useragent="buildkit/v0.10" http.response.contenttype="application/octet-stream" http.response.duration=7.82321ms http.response.status=200 http.response.written=0 
127.0.0.1 - - [12/Sep/2022:16:55:34 +0000] "HEAD /v2/acorn/acorn/blobs/sha256:8dbffc478db1b3dee9f43a7d5cfc7d94727286fb59cd0adb6902707b7a3c5682 HTTP/1.1" 200 0 "" "buildkit/v0.10"
127.0.0.1 - - [12/Sep/2022:16:55:34 +0000] "HEAD /v2/acorn/acorn/blobs/sha256:8ff0bb7e55e3a23d3d0f3dcaaa666d83b6128bfc307c1cb5198fc2112e7b12ce HTTP/1.1" 200 0 "" "buildkit/v0.10"
time="2022-09-12T16:55:34.167398495Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5000" http.request.id=2648a8f5-4d80-4ddb-8ad6-f7f09ffa8448 http.request.method=HEAD http.request.remoteaddr="127.0.0.1:38570" http.request.uri="/v2/acorn/acorn/blobs/sha256:8ff0bb7e55e3a23d3d0f3dcaaa666d83b6128bfc307c1cb5198fc2112e7b12ce" http.request.useragent="buildkit/v0.10" http.response.contenttype="application/octet-stream" http.response.duration="921.125µs" http.response.status=200 http.response.written=0 
127.0.0.1 - - [12/Sep/2022:16:55:34 +0000] "HEAD /v2/acorn/acorn/blobs/sha256:e90fd0a3e92bf52b1ec2d025eef70973afbb7293469958429832ce2deb27dfcd HTTP/1.1" 200 0 "" "buildkit/v0.10"
time="2022-09-12T16:55:34.165169035Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5000" http.request.id=6b72338e-be55-4fba-89a8-e846c2d5f347 http.request.method=HEAD http.request.remoteaddr="127.0.0.1:38576" http.request.uri="/v2/acorn/acorn/blobs/sha256:e90fd0a3e92bf52b1ec2d025eef70973afbb7293469958429832ce2deb27dfcd" http.request.useragent="buildkit/v0.10" http.response.contenttype="application/octet-stream" http.response.duration=6.32757ms http.response.status=200 http.response.written=0 
127.0.0.1 - - [12/Sep/2022:16:55:34 +0000] "HEAD /v2/acorn/acorn/blobs/sha256:c99be1b28c7fb4cf8f2b54b1bf6d0e4fd6961f76d04af0f24d09c055286057a7 HTTP/1.1" 200 0 "" "buildkit/v0.10"
time="2022-09-12T16:55:34.169991065Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5000" http.request.id=24b0ed10-ebb3-4d6f-8f3f-42410497da02 http.request.method=HEAD http.request.remoteaddr="127.0.0.1:38572" http.request.uri="/v2/acorn/acorn/blobs/sha256:c99be1b28c7fb4cf8f2b54b1bf6d0e4fd6961f76d04af0f24d09c055286057a7" http.request.useragent="buildkit/v0.10" http.response.contenttype="application/octet-stream" http.response.duration=5.143438ms http.response.status=200 http.response.written=0 
127.0.0.1 - - [12/Sep/2022:16:55:34 +0000] "HEAD /v2/acorn/acorn/manifests/latest HTTP/1.1" 200 523 "" "buildkit/v0.10"
time="2022-09-12T16:55:34.192091859Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5000" http.request.id=4008c4a0-47bd-4ca6-958b-8c1c38219ad9 http.request.method=HEAD http.request.remoteaddr="127.0.0.1:38576" http.request.uri="/v2/acorn/acorn/manifests/latest" http.request.useragent="buildkit/v0.10" http.response.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.response.duration=1.519041ms http.response.status=200 http.response.written=523 
127.0.0.1 - - [12/Sep/2022:16:55:34 +0000] "PUT /v2/acorn/acorn/manifests/latest HTTP/1.1" 201 0 "" "buildkit/v0.10"
time="2022-09-12T16:55:34.228135728Z" level=info msg="response completed" go.version=go1.11.2 http.request.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.request.host="127.0.0.1:5000" http.request.id=cebe1aa0-e843-4813-a321-d451572d5d7a http.request.method=PUT http.request.remoteaddr="127.0.0.1:38576" http.request.uri="/v2/acorn/acorn/manifests/latest" http.request.useragent="buildkit/v0.10" http.response.duration=34.048815ms http.response.status=201 http.response.written=0 
127.0.0.1 - - [12/Sep/2022:16:55:36 +0000] "GET /v2/ HTTP/1.1" 200 2 "" "Go-http-client/1.1"
time="2022-09-12T16:55:36.257993177Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5001" http.request.id=eb6400d0-e59e-47ad-bd97-b4c906c09384 http.request.method=GET http.request.remoteaddr="127.0.0.1:38636" http.request.uri="/v2/" http.request.useragent="Go-http-client/1.1" http.response.contenttype="application/json; charset=utf-8" http.response.duration="874.223µs" http.response.status=200 http.response.written=2 
127.0.0.1 - - [12/Sep/2022:16:55:36 +0000] "GET /v2/acorn/acorn/manifests/sha256:e11758331d99bfdbffc4804133868438bd380040fabc33dbbbc601542806a8f9 HTTP/1.1" 200 1571 "" "go-containerregistry/v0.11.0"
time="2022-09-12T16:55:36.409208233Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5001" http.request.id=3e856647-4a69-45b6-87be-a9d66d77b74c http.request.method=GET http.request.remoteaddr="127.0.0.1:38636" http.request.uri="/v2/acorn/acorn/manifests/sha256:e11758331d99bfdbffc4804133868438bd380040fabc33dbbbc601542806a8f9" http.request.useragent="go-containerregistry/v0.11.0" http.response.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.response.duration=1.12293ms http.response.status=200 http.response.written=1571 
time="2022-09-12T16:55:37.450387162Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5001" http.request.id=4e313d0b-f29f-4700-b971-82a76c6ea203 http.request.method=GET http.request.remoteaddr="127.0.0.1:38636" http.request.uri="/v2/" http.request.useragent="Go-http-client/1.1" http.response.contenttype="application/json; charset=utf-8" http.response.duration=1.278134ms http.response.status=200 http.response.written=2 
127.0.0.1 - - [12/Sep/2022:16:55:37 +0000] "GET /v2/ HTTP/1.1" 200 2 "" "Go-http-client/1.1"
127.0.0.1 - - [12/Sep/2022:16:55:37 +0000] "HEAD /v2/acorn/acorn/manifests/sha256:e11758331d99bfdbffc4804133868438bd380040fabc33dbbbc601542806a8f9 HTTP/1.1" 200 1571 "" "go-containerregistry/v0.11.0"
time="2022-09-12T16:55:37.599102451Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5001" http.request.id=6a465af9-8609-4b56-a96a-2b9f6143f95a http.request.method=HEAD http.request.remoteaddr="127.0.0.1:38636" http.request.uri="/v2/acorn/acorn/manifests/sha256:e11758331d99bfdbffc4804133868438bd380040fabc33dbbbc601542806a8f9" http.request.useragent="go-containerregistry/v0.11.0" http.response.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.response.duration=2.413765ms http.response.status=200 http.response.written=1571 
time="2022-09-12T16:55:37.767974881Z" level=info msg="response completed" go.version=go1.11.2 http.request.contenttype="application/vnd.oci.image.index.v1+json" http.request.host="127.0.0.1:5001" http.request.id=6bc42d78-6179-419e-a37a-7a5a3ac1acd5 http.request.method=PUT http.request.remoteaddr="127.0.0.1:38636" http.request.uri="/v2/acorn/acorn/manifests/sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a" http.request.useragent="go-containerregistry/v0.11.0" http.response.duration=21.960189ms http.response.status=201 http.response.written=0 
127.0.0.1 - - [12/Sep/2022:16:55:37 +0000] "PUT /v2/acorn/acorn/manifests/sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a HTTP/1.1" 201 0 "" "go-containerregistry/v0.11.0"
time="2022-09-12T16:55:40.10054185Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5000" http.request.id=5d955b7a-4810-4f3d-a241-e3cb20d21552 http.request.method=HEAD http.request.remoteaddr="127.0.0.1:38576" http.request.uri="/v2/acorn/acorn/blobs/sha256:983b6bde4e967e03c051c4e562b592869a813bb2f283747d40ff9b7887df5b10" http.request.useragent="buildkit/v0.10" http.response.contenttype="application/octet-stream" http.response.duration=1.003227ms http.response.status=200 http.response.written=0 
time="2022-09-12T16:55:40.101424774Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5000" http.request.id=5c34cabc-2260-4d7e-a430-da2ee07afba3 http.request.method=HEAD http.request.remoteaddr="127.0.0.1:38570" http.request.uri="/v2/acorn/acorn/blobs/sha256:c9c22f85021fdc051efd3b75070f13d6fce39c566e78f5e8da7f2460eb340e6b" http.request.useragent="buildkit/v0.10" http.response.contenttype="application/octet-stream" http.response.duration=1.87385ms http.response.status=200 http.response.written=0 
127.0.0.1 - - [12/Sep/2022:16:55:40 +0000] "HEAD /v2/acorn/acorn/blobs/sha256:983b6bde4e967e03c051c4e562b592869a813bb2f283747d40ff9b7887df5b10 HTTP/1.1" 200 0 "" "buildkit/v0.10"
127.0.0.1 - - [12/Sep/2022:16:55:40 +0000] "HEAD /v2/acorn/acorn/blobs/sha256:c9c22f85021fdc051efd3b75070f13d6fce39c566e78f5e8da7f2460eb340e6b HTTP/1.1" 200 0 "" "buildkit/v0.10"
time="2022-09-12T16:55:40.11021891Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5000" http.request.id=9a880bca-7d34-49ef-bf20-a7eab956ff50 http.request.method=HEAD http.request.remoteaddr="127.0.0.1:38570" http.request.uri="/v2/acorn/acorn/manifests/latest" http.request.useragent="buildkit/v0.10" http.response.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.response.duration=2.436165ms http.response.status=200 http.response.written=1571 
127.0.0.1 - - [12/Sep/2022:16:55:40 +0000] "HEAD /v2/acorn/acorn/manifests/latest HTTP/1.1" 200 1571 "" "buildkit/v0.10"
time="2022-09-12T16:55:40.139714601Z" level=info msg="response completed" go.version=go1.11.2 http.request.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.request.host="127.0.0.1:5000" http.request.id=041a896c-674b-447c-af98-d16e722eb5eb http.request.method=PUT http.request.remoteaddr="127.0.0.1:38570" http.request.uri="/v2/acorn/acorn/manifests/latest" http.request.useragent="buildkit/v0.10" http.response.duration=27.840347ms http.response.status=201 http.response.written=0 
127.0.0.1 - - [12/Sep/2022:16:55:40 +0000] "PUT /v2/acorn/acorn/manifests/latest HTTP/1.1" 201 0 "" "buildkit/v0.10"
time="2022-09-12T16:55:42.279829808Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5001" http.request.id=1693d495-4259-4c75-a0f2-54d063f2d7c5 http.request.method=GET http.request.remoteaddr="127.0.0.1:44770" http.request.uri="/v2/" http.request.useragent="Go-http-client/1.1" http.response.contenttype="application/json; charset=utf-8" http.response.duration="990.027µs" http.response.status=200 http.response.written=2 
127.0.0.1 - - [12/Sep/2022:16:55:42 +0000] "GET /v2/ HTTP/1.1" 200 2 "" "Go-http-client/1.1"
time="2022-09-12T16:55:42.426300937Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5001" http.request.id=4c95e633-a9f3-4af9-9a94-805af3898c2c http.request.method=GET http.request.remoteaddr="127.0.0.1:44770" http.request.uri="/v2/acorn/acorn/manifests/sha256:074e996b15e8cc2c5cfcc575528618a048df4c6ef8abfab4bb55b1354c6730c8" http.request.useragent="go-containerregistry/v0.11.0" http.response.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.response.duration=1.304635ms http.response.status=200 http.response.written=523 
127.0.0.1 - - [12/Sep/2022:16:55:42 +0000] "GET /v2/acorn/acorn/manifests/sha256:074e996b15e8cc2c5cfcc575528618a048df4c6ef8abfab4bb55b1354c6730c8 HTTP/1.1" 200 523 "" "go-containerregistry/v0.11.0"
time="2022-09-12T16:55:43.42703148Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5001" http.request.id=8346ae1a-954f-44f7-adbe-a68fd6439af5 http.request.method=GET http.request.remoteaddr="127.0.0.1:44770" http.request.uri="/v2/" http.request.useragent="Go-http-client/1.1" http.response.contenttype="application/json; charset=utf-8" http.response.duration=1.636644ms http.response.status=200 http.response.written=2 
127.0.0.1 - - [12/Sep/2022:16:55:43 +0000] "GET /v2/ HTTP/1.1" 200 2 "" "Go-http-client/1.1"
127.0.0.1 - - [12/Sep/2022:16:55:43 +0000] "GET /v2/acorn/acorn/manifests/sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a HTTP/1.1" 200 246 "" "go-containerregistry/v0.11.0"
time="2022-09-12T16:55:43.576974802Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5001" http.request.id=96723fca-8962-4c85-88d2-2f2d2e83cfcb http.request.method=GET http.request.remoteaddr="127.0.0.1:44770" http.request.uri="/v2/acorn/acorn/manifests/sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a" http.request.useragent="go-containerregistry/v0.11.0" http.response.contenttype="application/vnd.oci.image.index.v1+json" http.response.duration=1.221632ms http.response.status=200 http.response.written=246 
127.0.0.1 - - [12/Sep/2022:16:55:44 +0000] "GET /v2/ HTTP/1.1" 200 2 "" "Go-http-client/1.1"
time="2022-09-12T16:55:44.535832299Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5001" http.request.id=02b7deb6-3d15-42f1-8dd1-78e24451de10 http.request.method=GET http.request.remoteaddr="127.0.0.1:44770" http.request.uri="/v2/" http.request.useragent="Go-http-client/1.1" http.response.contenttype="application/json; charset=utf-8" http.response.duration="768.121µs" http.response.status=200 http.response.written=2 
127.0.0.1 - - [12/Sep/2022:16:55:44 +0000] "HEAD /v2/acorn/acorn/manifests/sha256:074e996b15e8cc2c5cfcc575528618a048df4c6ef8abfab4bb55b1354c6730c8 HTTP/1.1" 200 523 "" "go-containerregistry/v0.11.0"
time="2022-09-12T16:55:44.681192735Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5001" http.request.id=243f5aef-9591-4c13-9372-d6bedc1d8373 http.request.method=HEAD http.request.remoteaddr="127.0.0.1:44770" http.request.uri="/v2/acorn/acorn/manifests/sha256:074e996b15e8cc2c5cfcc575528618a048df4c6ef8abfab4bb55b1354c6730c8" http.request.useragent="go-containerregistry/v0.11.0" http.response.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.response.duration=1.267034ms http.response.status=200 http.response.written=523 
time="2022-09-12T16:55:44.824920227Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5001" http.request.id=37c22a52-6a95-46c7-a49b-d2a00b85bb5d http.request.method=HEAD http.request.remoteaddr="127.0.0.1:44770" http.request.uri="/v2/acorn/acorn/manifests/sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a" http.request.useragent="go-containerregistry/v0.11.0" http.response.contenttype="application/vnd.oci.image.index.v1+json" http.response.duration=1.198932ms http.response.status=200 http.response.written=246 
127.0.0.1 - - [12/Sep/2022:16:55:44 +0000] "HEAD /v2/acorn/acorn/manifests/sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a HTTP/1.1" 200 246 "" "go-containerregistry/v0.11.0"
time="2022-09-12T16:55:45.021274244Z" level=info msg="response completed" go.version=go1.11.2 http.request.contenttype="application/vnd.oci.image.index.v1+json" http.request.host="127.0.0.1:5001" http.request.id=7a28100f-2097-4f70-adbb-f02b2150be20 http.request.method=PUT http.request.remoteaddr="127.0.0.1:44770" http.request.uri="/v2/acorn/acorn/manifests/61a4f3a1234a2868f36bd39c93b73ae0161a9e0b5612d83aa79cbaf12ad5a1e3" http.request.useragent="go-containerregistry/v0.11.0" http.response.duration=51.411492ms http.response.status=201 http.response.written=0 
127.0.0.1 - - [12/Sep/2022:16:55:44 +0000] "PUT /v2/acorn/acorn/manifests/61a4f3a1234a2868f36bd39c93b73ae0161a9e0b5612d83aa79cbaf12ad5a1e3 HTTP/1.1" 201 0 "" "go-containerregistry/v0.11.0"
10.244.0.21 - - [12/Sep/2022:16:55:45 +0000] "GET /v2/ HTTP/1.1" 200 2 "" "Go-http-client/1.1"
time="2022-09-12T16:55:45.77708491Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5000" http.request.id=daa1cdb8-6b7f-4382-b99e-dbe0bb275bee http.request.method=GET http.request.remoteaddr="10.244.0.21:44048" http.request.uri="/v2/" http.request.useragent="Go-http-client/1.1" http.response.contenttype="application/json; charset=utf-8" http.response.duration="912.225µs" http.response.status=200 http.response.written=2 
time="2022-09-12T16:55:45.779735582Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5000" http.request.id=f125c49b-6433-4ff9-bed0-9db66c65a866 http.request.method=GET http.request.remoteaddr="10.244.0.21:44048" http.request.uri="/v2/acorn/acorn/tags/list?n=1000" http.request.useragent="go-containerregistry/v0.11.0" http.response.contenttype="application/json; charset=utf-8" http.response.duration="991.727µs" http.response.status=200 http.response.written=108 
10.244.0.21 - - [12/Sep/2022:16:55:45 +0000] "GET /v2/acorn/acorn/tags/list?n=1000 HTTP/1.1" 200 108 "" "go-containerregistry/v0.11.0"
time="2022-09-12T16:55:45.955872751Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5000" http.request.id=e157796a-73ec-47a6-8878-76bd4d05cfd4 http.request.method=GET http.request.remoteaddr="10.244.0.21:44052" http.request.uri="/v2/" http.request.useragent="Go-http-client/1.1" http.response.contenttype="application/json; charset=utf-8" http.response.duration="850.123µs" http.response.status=200 http.response.written=2 
10.244.0.21 - - [12/Sep/2022:16:55:45 +0000] "GET /v2/ HTTP/1.1" 200 2 "" "Go-http-client/1.1"
10.244.0.21 - - [12/Sep/2022:16:55:45 +0000] "GET /v2/acorn/acorn/tags/list?n=1000 HTTP/1.1" 200 108 "" "go-containerregistry/v0.11.0"
time="2022-09-12T16:55:45.958094111Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5000" http.request.id=9c15dd46-dae4-4ce8-b467-23298afa479e http.request.method=GET http.request.remoteaddr="10.244.0.21:44052" http.request.uri="/v2/acorn/acorn/tags/list?n=1000" http.request.useragent="go-containerregistry/v0.11.0" http.response.contenttype="application/json; charset=utf-8" http.response.duration="891.124µs" http.response.status=200 http.response.written=108 

## acorn images logs:
0.244.0.21 - - [12/Sep/2022:16:57:01 +0000] "GET /v2/ HTTP/1.1" 200 2 "" "Go-http-client/1.1"
time="2022-09-12T16:57:01.560099759Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5000" http.request.id=ac3ff381-5aaa-4952-9ea4-5cc1213c1151 http.request.method=GET http.request.remoteaddr="10.244.0.21:57590" http.request.uri="/v2/" http.request.useragent="Go-http-client/1.1" http.response.contenttype="application/json; charset=utf-8" http.response.duration="925.625µs" http.response.status=200 http.response.written=2 
time="2022-09-12T16:57:01.562372021Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="127.0.0.1:5000" http.request.id=d290c7e3-adff-4f26-8bc6-751842e385e4 http.request.method=GET http.request.remoteaddr="10.244.0.21:57590" http.request.uri="/v2/acorn/acorn/tags/list?n=1000" http.request.useragent="go-containerregistry/v0.11.0" http.response.contenttype="application/json; charset=utf-8" http.response.duration="857.623µs" http.response.status=200 http.response.written=108 
10.244.0.21 - - [12/Sep/2022:16:57:01 +0000] "GET /v2/acorn/acorn/tags/list?n=1000 HTTP/1.1" 200 108 "" "go-containerregistry/v0.11.0"

However when trying to run spawn the app from the image, containerd is not able to access AKS worker node on 127.0.0.1:, where the PORT is the nodeport exposed by the registry service.

kubectl get svc -n acorn-system registry
NAME       TYPE       CLUSTER-IP     EXTERNAL-IP   PORT(S)          AGE
registry   NodePort   10.0.161.105   <none>        5000:30077/TCP   114m

NAME         IMAGE      HEALTHY   UP-TO-DATE   CREATED   ENDPOINTS   MESSAGE
cold-smoke   app:test   0/1       1            9s ago                [containers: app ErrImagePull: rpc error: code = Unknown desc = failed to pull and unpack image "127.0.0.1:30077/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a": failed to resolve reference "127.0.0.1:30077/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a": failed to do request: Head "https://127.0.0.1:30077/v2/acorn/acorn/manifests/sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a": http: server gave HTTP response to HTTPS client; cold-smoke is not ready]
meldafrawi commented 2 years ago

iptables on worker nodes related to acorn service

nodeport is 31889 instead of 30077 since this is a new cluster.

61:-A KUBE-EXT-BZHNP6MBNJLUZE57 -m comment --comment "masquerade traffic for acorn-system/registry:registry external destinations" -j KUBE-MARK-MASQ
71:-A KUBE-NODEPORTS -p tcp -m comment --comment "acorn-system/registry:registry" -m tcp --dport 31889 -j KUBE-EXT-BZHNP6MBNJLUZE57
87:-A KUBE-SEP-FNM7T623XI7T5E4Y -s 10.244.0.27/32 -m comment --comment "acorn-system/registry:registry" -j KUBE-MARK-MASQ
88:-A KUBE-SEP-FNM7T623XI7T5E4Y -p tcp -m comment --comment "acorn-system/registry:registry" -m tcp -j DNAT [unsupported revision]
93:-A KUBE-SEP-RBULNE6WKM6H5P3Y -s 10.244.0.32/32 -m comment --comment "acorn-system/acorn-api" -j KUBE-MARK-MASQ
94:-A KUBE-SEP-RBULNE6WKM6H5P3Y -p tcp -m comment --comment "acorn-system/acorn-api" -m tcp -j DNAT [unsupported revision]
103:-A KUBE-SERVICES -d 10.0.178.34/32 -p tcp -m comment --comment "acorn-system/acorn-api cluster IP" -m tcp --dport 7443 -j KUBE-SVC-LHZADFCNGOY2F2PC
104:-A KUBE-SERVICES -d 10.0.131.230/32 -p tcp -m comment --comment "acorn-system/registry:registry cluster IP" -m tcp --dport 5000 -j KUBE-SVC-BZHNP6MBNJLUZE57
110:-A KUBE-SVC-BZHNP6MBNJLUZE57 ! -s 10.244.0.0/16 -d 10.0.131.230/32 -p tcp -m comment --comment "acorn-system/registry:registry cluster IP" -m tcp --dport 5000 -j KUBE-MARK-MASQ
111:-A KUBE-SVC-BZHNP6MBNJLUZE57 -m comment --comment "acorn-system/registry:registry -> 10.244.0.27:5000" -j KUBE-SEP-FNM7T623XI7T5E4Y
115:-A KUBE-SVC-LHZADFCNGOY2F2PC ! -s 10.244.0.0/16 -d 10.0.178.34/32 -p tcp -m comment --comment "acorn-system/acorn-api cluster IP" -m tcp --dport 7443 -j KUBE-MARK-MASQ
116:-A KUBE-SVC-LHZADFCNGOY2F2PC -m comment --comment "acorn-system/acorn-api -> 10.244.0.32:7443" -j KUBE-SEP-RBULNE6WKM6H5P3Y
156:-A KUBE-FIREWALL ! -s 127.0.0.0/8 -d 127.0.0.0/8 -m comment --comment "block incoming localnet connections" -m conntrack ! --ctstate RELATED,ESTABLISHED,DNAT -j DROP
meldafrawi commented 2 years ago

I've tried to pull the image using crt, i was able to pull the image when only using --plain-http option

ctr i pull 127.0.0.1:31889/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a --plain-http
127.0.0.1:31889/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a: resolved       |++++++++++++++++++++++++++++++++++++++| 
index-sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a:                       done           |++++++++++++++++++++++++++++++++++++++| 
manifest-sha256:e11758331d99bfdbffc4804133868438bd380040fabc33dbbbc601542806a8f9:                    done           |++++++++++++++++++++++++++++++++++++++| 
layer-sha256:7402bc4c98a0e78307c5d13c4c87ab3fd18e238b6752181d6b7669855c0845c4:                       done           |++++++++++++++++++++++++++++++++++++++| 
config-sha256:e90fd0a3e92bf52b1ec2d025eef70973afbb7293469958429832ce2deb27dfcd:                      done           |++++++++++++++++++++++++++++++++++++++| 
layer-sha256:213ec9aee27d8be045c6a92b7eac22c9a64b44558193775a1a7f626352392b49:                       done           |++++++++++++++++++++++++++++++++++++++| 
layer-sha256:c99be1b28c7fb4cf8f2b54b1bf6d0e4fd6961f76d04af0f24d09c055286057a7:                       done           |++++++++++++++++++++++++++++++++++++++| 
layer-sha256:8ff0bb7e55e3a23d3d0f3dcaaa666d83b6128bfc307c1cb5198fc2112e7b12ce:                       done           |++++++++++++++++++++++++++++++++++++++| 
layer-sha256:6d80de393db7bb6d3178742ef3dc3e905253dd47165fb9eeb53a50993c699262:                       done           |++++++++++++++++++++++++++++++++++++++| 
layer-sha256:8dbffc478db1b3dee9f43a7d5cfc7d94727286fb59cd0adb6902707b7a3c5682:                       done           |++++++++++++++++++++++++++++++++++++++| 
elapsed: 0.4 s                                                                                       total:  8.6 Mi (21.6 MiB/s)                                      
unpacking linux/amd64 sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a...
done: 599.104271ms

but without the option, I get the following error:

ctr i pull 127.0.0.1:31889/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a 
INFO[0000] trying next host                              error="failed to do request: Head \"https://127.0.0.1:31889/v2/acorn/acorn/manifests/sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a\": http: server gave HTTP response to HTTPS client" host="127.0.0.1:31889"
INFO[0000] trying next host                              error="failed to do request: Head \"https://127.0.0.1:31889/v2/acorn/acorn/blobs/sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a\": http: server gave HTTP response to HTTPS client" host="127.0.0.1:31889"
ctr: failed to resolve reference "127.0.0.1:31889/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a": failed to do request: Head "https://127.0.0.1:31889/v2/acorn/acorn/manifests/sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a": http: server gave HTTP response to HTTPS client
root@aks-nodepool1-14481657-vmss000000:~# Connection to localhost closed by remote host.
Connection to localhost closed.

it is the same error on containerd logs when trying to run the app using acorn

journalctl -xe -u  containerd.service -f

Sep 12 23:54:24 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:24.993874480Z" level=info msg="Portforward for \"709cdc662a9234615eb9f4900f1f0da0fdf671c4a845becb3f83e0a65f41dcc7\" port [5000]"
Sep 12 23:54:24 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:24.993937081Z" level=info msg="Portforward for \"709cdc662a9234615eb9f4900f1f0da0fdf671c4a845becb3f83e0a65f41dcc7\" returns URL \"http://127.0.0.1:39243/portforward/2ZtjD5Km\""
Sep 12 23:54:24 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:24.994517691Z" level=info msg="Executing port forwarding in network namespace \"/var/run/netns/cni-d27d65c7-29e4-ce3d-5a1f-60f6093c57c0\""
Sep 12 23:54:24 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:24.999912582Z" level=info msg="Finish port forwarding for \"709cdc662a9234615eb9f4900f1f0da0fdf671c4a845becb3f83e0a65f41dcc7\" port 5000"
Sep 12 23:54:25 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:25.048992012Z" level=info msg="Portforward for \"709cdc662a9234615eb9f4900f1f0da0fdf671c4a845becb3f83e0a65f41dcc7\" port [5000]"
Sep 12 23:54:25 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:25.049046413Z" level=info msg="Portforward for \"709cdc662a9234615eb9f4900f1f0da0fdf671c4a845becb3f83e0a65f41dcc7\" returns URL \"http://127.0.0.1:39243/portforward/c2o9bVuE\""
Sep 12 23:54:25 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:25.049708524Z" level=info msg="Executing port forwarding in network namespace \"/var/run/netns/cni-d27d65c7-29e4-ce3d-5a1f-60f6093c57c0\""
Sep 12 23:54:25 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:25.238657917Z" level=info msg="Portforward for \"709cdc662a9234615eb9f4900f1f0da0fdf671c4a845becb3f83e0a65f41dcc7\" port [5000]"
Sep 12 23:54:25 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:25.238722619Z" level=info msg="Portforward for \"709cdc662a9234615eb9f4900f1f0da0fdf671c4a845becb3f83e0a65f41dcc7\" returns URL \"http://127.0.0.1:39243/portforward/Kf21-85u\""
Sep 12 23:54:25 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:25.239390530Z" level=info msg="Executing port forwarding in network namespace \"/var/run/netns/cni-d27d65c7-29e4-ce3d-5a1f-60f6093c57c0\""
Sep 12 23:54:25 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:25.244726120Z" level=info msg="Finish port forwarding for \"709cdc662a9234615eb9f4900f1f0da0fdf671c4a845becb3f83e0a65f41dcc7\" port 5000"
Sep 12 23:54:25 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:25.295360376Z" level=info msg="Portforward for \"709cdc662a9234615eb9f4900f1f0da0fdf671c4a845becb3f83e0a65f41dcc7\" port [5000]"
Sep 12 23:54:25 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:25.295422977Z" level=info msg="Portforward for \"709cdc662a9234615eb9f4900f1f0da0fdf671c4a845becb3f83e0a65f41dcc7\" returns URL \"http://127.0.0.1:39243/portforward/3tGYBlUs\""
Sep 12 23:54:25 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:25.296348192Z" level=info msg="Executing port forwarding in network namespace \"/var/run/netns/cni-d27d65c7-29e4-ce3d-5a1f-60f6093c57c0\""
Sep 12 23:54:26 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:26.098840456Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:app-5c7fb57557-6hm7x,Uid:69125832-3a0e-4552-9526-6ff0ec5c0d5f,Namespace:broken-mountain-10dabe83-8de,Attempt:0,}"
Sep 12 23:54:26 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:26.223173057Z" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1
Sep 12 23:54:26 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:26.223233858Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1
Sep 12 23:54:26 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:26.223249458Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
Sep 12 23:54:26 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:26.223834568Z" level=info msg="starting signal loop" namespace=k8s.io path=/run/containerd/io.containerd.runtime.v2.task/k8s.io/f59c640f7536c823182a79443d487ff47f271b20a47240f03f85cad8d7d981a1 pid=22151 runtime=io.containerd.runc.v2
Sep 12 23:54:26 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:26.317941259Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:app-5c7fb57557-6hm7x,Uid:69125832-3a0e-4552-9526-6ff0ec5c0d5f,Namespace:broken-mountain-10dabe83-8de,Attempt:0,} returns sandbox id \"f59c640f7536c823182a79443d487ff47f271b20a47240f03f85cad8d7d981a1\""
Sep 12 23:54:26 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:26.322069229Z" level=info msg="PullImage \"127.0.0.1:31889/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a\""
Sep 12 23:54:26 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:26.331932995Z" level=info msg="trying next host" error="failed to do request: Head \"https://127.0.0.1:31889/v2/acorn/acorn/manifests/sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a\": http: server gave HTTP response to HTTPS client" host="127.0.0.1:31889"
Sep 12 23:54:26 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:26.333011713Z" level=info msg="trying next host" error="failed to do request: Head \"https://127.0.0.1:31889/v2/acorn/acorn/blobs/sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a\": http: server gave HTTP response to HTTPS client" host="127.0.0.1:31889"
Sep 12 23:54:26 aks-nodepool1-14481657-vmss000000 containerd[1153]: time="2022-09-12T23:54:26.336218268Z" level=error msg="PullImage \"127.0.0.1:31889/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a\" failed" error="failed to pull and unpack image \"127.0.0.1:31889/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a\": failed to resolve reference \"127.0.0.1:31889/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a\": failed to do request: Head \"https://127.0.0.1:31889/v2/acorn/acorn/manifests/sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a\": http: server gave HTTP response to HTTPS client"
meldafrawi commented 2 years ago

Observing kubelet logs:

Sep 13 00:08:48 aks-nodepool1-14481657-vmss000000 kubelet[2627]: I0913 00:08:48.359077    2627 kubelet.go:2072] "SyncLoop ADD" source="api" pods=[twilight-sun-d7b39321-616/app-7874f8445b-2jqqx]
Sep 13 00:08:48 aks-nodepool1-14481657-vmss000000 kubelet[2627]: I0913 00:08:48.359126    2627 topology_manager.go:200] "Topology Admit Handler"
Sep 13 00:08:48 aks-nodepool1-14481657-vmss000000 kubelet[2627]: I0913 00:08:48.549789    2627 reconciler.go:270] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-jggwl\" (UniqueName: \"kubernetes.io/projected/0c02278d-fb4b-4d3c-8c2f-38c5d0861818-kube-api-access-jggwl\") pod \"app-7874f8445b-2jqqx\" (UID: \"0c02278d-fb4b-4d3c-8c2f-38c5d0861818\") " pod="twilight-sun-d7b39321-616/app-7874f8445b-2jqqx"
Sep 13 00:08:48 aks-nodepool1-14481657-vmss000000 kubelet[2627]: I0913 00:08:48.651300    2627 reconciler.go:245] "operationExecutor.MountVolume started for volume \"kube-api-access-jggwl\" (UniqueName: \"kubernetes.io/projected/0c02278d-fb4b-4d3c-8c2f-38c5d0861818-kube-api-access-jggwl\") pod \"app-7874f8445b-2jqqx\" (UID: \"0c02278d-fb4b-4d3c-8c2f-38c5d0861818\") " pod="twilight-sun-d7b39321-616/app-7874f8445b-2jqqx"
Sep 13 00:08:48 aks-nodepool1-14481657-vmss000000 kubelet[2627]: I0913 00:08:48.707345    2627 operation_generator.go:703] "MountVolume.SetUp succeeded for volume \"kube-api-access-jggwl\" (UniqueName: \"kubernetes.io/projected/0c02278d-fb4b-4d3c-8c2f-38c5d0861818-kube-api-access-jggwl\") pod \"app-7874f8445b-2jqqx\" (UID: \"0c02278d-fb4b-4d3c-8c2f-38c5d0861818\") " pod="twilight-sun-d7b39321-616/app-7874f8445b-2jqqx"
Sep 13 00:08:48 aks-nodepool1-14481657-vmss000000 kubelet[2627]: I0913 00:08:48.977942    2627 kuberuntime_manager.go:469] "No sandbox for pod can be found. Need to start a new one" pod="twilight-sun-d7b39321-616/app-7874f8445b-2jqqx"
Sep 13 00:08:49 aks-nodepool1-14481657-vmss000000 kubelet[2627]: I0913 00:08:49.234448    2627 azure_credentials.go:221] image(127.0.0.1:31889/acorn/acorn) is not from ACR, return empty authentication
Sep 13 00:08:49 aks-nodepool1-14481657-vmss000000 kubelet[2627]: E0913 00:08:49.244075    2627 remote_image.go:238] "PullImage from image service failed" err="rpc error: code = Unknown desc = failed to pull and unpack image \"127.0.0.1:31889/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a\": failed to resolve reference \"127.0.0.1:31889/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a\": failed to do request: Head \"https://127.0.0.1:31889/v2/acorn/acorn/manifests/sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a\": http: server gave HTTP response to HTTPS client" image="127.0.0.1:31889/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a"
Sep 13 00:08:49 aks-nodepool1-14481657-vmss000000 kubelet[2627]: E0913 00:08:49.244183    2627 kuberuntime_manager.go:905] container &Container{Name:app,Image:127.0.0.1:31889/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a,Command:[],Args:[],WorkingDir:,Ports:[]ContainerPort{},Env:[]EnvVar{},Resources:ResourceRequirements{Limits:ResourceList{},Requests:ResourceList{},},VolumeMounts:[]VolumeMount{VolumeMount{Name:kube-api-access-jggwl,ReadOnly:true,MountPath:/var/run/secrets/kubernetes.io/serviceaccount,SubPath:,MountPropagation:nil,SubPathExpr:,},},LivenessProbe:nil,ReadinessProbe:nil,Lifecycle:nil,TerminationMessagePath:/dev/termination-log,ImagePullPolicy:IfNotPresent,SecurityContext:nil,Stdin:false,StdinOnce:false,TTY:false,EnvFrom:[]EnvFromSource{},TerminationMessagePolicy:File,VolumeDevices:[]VolumeDevice{},StartupProbe:nil,} start failed in pod app-7874f8445b-2jqqx_twilight-sun-d7b39321-616(0c02278d-fb4b-4d3c-8c2f-38c5d0861818): ErrImagePull: rpc error: code = Unknown desc = failed to pull and unpack image "127.0.0.1:31889/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a": failed to resolve reference "127.0.0.1:31889/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a": failed to do request: Head "https://127.0.0.1:31889/v2/acorn/acorn/manifests/sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a": http: server gave HTTP response to HTTPS client
Sep 13 00:08:49 aks-nodepool1-14481657-vmss000000 kubelet[2627]: E0913 00:08:49.244297    2627 pod_workers.go:951] "Error syncing pod, skipping" err="failed to \"StartContainer\" for \"app\" with ErrImagePull: \"rpc error: code = Unknown desc = failed to pull and unpack image \\\"127.0.0.1:31889/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a\\\": failed to resolve reference \\\"127.0.0.1:31889/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a\\\": failed to do request: Head \\\"https://127.0.0.1:31889/v2/acorn/acorn/manifests/sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a\\\": http: server gave HTTP response to HTTPS client\"" pod="twilight-sun-d7b39321-616/app-7874f8445b-2jqqx" podUID=0c02278d-fb4b-4d3c-8c2f-38c5d0861818
Sep 13 00:08:50 aks-nodepool1-14481657-vmss000000 kubelet[2627]: I0913 00:08:50.003103    2627 kubelet.go:2110] "SyncLoop (PLEG): event for pod" pod="twilight-sun-d7b39321-616/app-7874f8445b-2jqqx" event=&{ID:0c02278d-fb4b-4d3c-8c2f-38c5d0861818 Type:ContainerStarted Data:70144d0e08a6bc6bbc3341059a3f3dcbdea5115bbffad312eb88525f208ebfce}
Sep 13 00:08:50 aks-nodepool1-14481657-vmss000000 kubelet[2627]: E0913 00:08:50.004077    2627 pod_workers.go:951] "Error syncing pod, skipping" err="failed to \"StartContainer\" for \"app\" with ImagePullBackOff: \"Back-off pulling image \\\"127.0.0.1:31889/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a\\\"\"" pod="twilight-sun-d7b39321-616/app-7874f8445b-2jqqx" podUID=0c02278d-fb4b-4d3c-8c2f-38c5d0861818
Sep 13 00:08:51 aks-nodepool1-14481657-vmss000000 kubelet[2627]: I0913 00:08:51.230913    2627 logs.go:320] "Finished parsing log file" path="/var/log/pods/kube-system_kube-proxy-shswj_8b6207b9-e749-4a79-b607-8d6e6292375e/kube-proxy/1.log"
Sep 13 00:08:51 aks-nodepool1-14481657-vmss000000 kubelet[2627]: I0913 00:08:51.446543    2627 logs.go:320] "Finished parsing log file" path="/var/log/pods/kube-system_kube-proxy-shswj_8b6207b9-e749-4a79-b607-8d6e6292375e/kube-proxy/0.log"
Sep 13 00:08:52 aks-nodepool1-14481657-vmss000000 kubelet[2627]: E0913 00:08:52.811661    2627 pod_workers.go:951] "Error syncing pod, skipping" err="failed to \"StartContainer\" for \"app\" with ImagePullBackOff: \"Back-off pulling image \\\"127.0.0.1:31889/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a\\\"\"" pod="cold-glade-02b9e1d2-dbd/app-6df8c56d5f-567lx" podUID=adad2ac3-06cf-491e-ae4d-97c9ca059413
Sep 13 00:08:53 aks-nodepool1-14481657-vmss000000 kubelet[2627]: E0913 00:08:53.815354    2627 pod_workers.go:951] "Error syncing pod, skipping" err="failed to \"StartContainer\" for \"app\" with ImagePullBackOff: \"Back-off pulling image \\\"127.0.0.1:31889/acorn/acorn@sha256:438b33ad07ea40f5c8cbbbc893b0faa2ed204dafac880c73ae6359b8f20ce17a\\\"\"" pod="broken-mountain-10dabe83-8de/app-5c7fb57557-6hm7x" podUID=69125832-3a0e-4552-9526-6ff0ec5c0d5f

seems similar to https://github.com/containerd/containerd/issues/4141

checking containerd config, we found

  [plugins."io.containerd.grpc.v1.cri".registry]
    config_path = "/etc/containerd/certs.d"

Thanks to @ibuildthecloud, and according to https://github.com/containerd/containerd/blame/1764ea9a2815ddbd0cde777b557f97171b84cd02/pkg/cri/server/image_pull.go#L336

setting config_path disables the "default to http" behavior for localhost`

meldafrawi commented 2 years ago

Ref: https://github.com/containerd/containerd/issues/7392