Node take 100s to start #3102

royb-tabit · 2022-12-22T11:50:47Z

Version

Karpenter Version:__ v0.20.0
Kubernetes Version:__ v1.23

Expected Behavior

Node to be in Ready state in about 60 seconds or less

Actual Behavior

000s instance registered to the cluster
038s cloud-init finish
055s kube-proxy is running
between
080s
and
100s Node is in Ready state

When comparing to "aws-autoscaler" performance
with the same lunchTemplet we get about 70s
until Node is in ready state.

Steps to Reproduce the Problem

AMI-ID (used in launchTemplate):
ami-0c64fd5283c4bfc45

Name:                   rosapi-dev
Namespace:              applications
Labels:                 app.kubernetes.io/instance=rosapi-dev
                        app.kubernetes.io/managed-by=Helm
                        app.kubernetes.io/name=rosapi-dev
                        helm.sh/chart=k8s-service-0.2.0
Annotations:            deployment.kubernetes.io/revision: 43
                        meta.helm.sh/release-name: rosapi-dev
                        meta.helm.sh/release-namespace: applications
                        sidecar.jaegertracing.io/inject: false
Selector:               app.kubernetes.io/instance=rosapi-dev,app.kubernetes.io/name=rosapi-dev,g
runtwork.io/deployment-type=main
Replicas:               1 desired | 1 updated | 1 total | 1 available | 0 unavailable
StrategyType:           RollingUpdate
MinReadySeconds:        0
RollingUpdateStrategy:  25% max unavailable, 25% max surge
Pod Template:
  Labels:           app.kubernetes.io/instance=rosapi-dev
                    app.kubernetes.io/name=rosapi-dev
                    gruntwork.io/deployment-type=main
  Annotations:      kubectl.kubernetes.io/restartedAt: 2022-12-09T18:47:05Z
                    prometheus.io/path: /metrics
                    prometheus.io/port: 1234
                    prometheus.io/scrape: true
  Service Account:  rosapi-dev
  Containers:
   rosapi-dev:
    Image:       ${my_account}.dkr.ecr.eu-west-1.amazonaws.com/rosapi-dev:tag
    Ports:       1234/TCP, 1234/TCP, 1234/TCP
    Host Ports:  0/TCP, 0/TCP, 0/TCP
    Command:
      node
      inpact.js
    Limits:
      cpu:     500m
      memory:  1000Mi
    Requests:
      cpu:     500m
      memory:  1000Mi
    Liveness:  http-get http://:liveness/status delay=15s timeout=2s period=30s #success=1 #failu
re=3
    Startup:   http-get http://:1234/status%3FstartupProbe delay=0s timeout=1s period=10s #succes
s=1 #failure=30
    Environment:
		...
    Mounts:
      /tmp/LogDir from my-volume (rw)
  Volumes:
   my-volume:
    Type:       EmptyDir (a temporary directory that shares a pod's lifetime)
    Medium:
    SizeLimit:  <unset>
  sidecar:
    Image:      ${my_account}.dkr.ecr.eu-west-1.amazonaws.com/tabit-filebeat:tag
    Port:       80/TCP
    Host Port:  0/TCP
    Limits:
      cpu:     250m
      memory:  500Mi
    Requests:
      cpu:     250m
      memory:  500Mi
    Environment:
		..
    Mounts:
      /tmp/LogDir from my-volume (rw)
  Volumes:
   my-volume:
    Type:       EmptyDir (a temporary directory that shares a pod's lifetime)
    Medium:
    SizeLimit:  <unset>

  apiVersion: karpenter.sh/v1alpha5
  kind: Provisioner
  metadata:
    name: arm
  spec:
    consolidation:
      enabled: true
    requirements:
      - key: karpenter.sh/capacity-type
        operator: In
        values: ["spot", "on-demand"]
      - key: kubernetes.io/arch
        operator: In
        values:
          - arm64
    limits:
      resources:
        cpu: 1000
    providerRef:
      name: arm
    ttlSecondsUntilExpired: 2592000

apiVersion: karpenter.k8s.aws/v1alpha1
  kind: AWSNodeTemplate
  metadata:
    name: arm
  spec:
    subnetSelector:
      aws-ids: my-subnets
    tags:
      karpenter.sh/discovery: my-cluster
    launchTemplate: my-template

USER-DATA:

MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="//"

--//
Content-Type: text/x-shellscript; charset="us-ascii"
#!/bin/bash
set -ex
B64_CLUSTER_CA=MY_CERTIFICATE API_SERVER_URL=MY_URL
K8S_CLUSTER_DNS_IP=My_IP
/etc/eks/bootstrap.sh eks-dev --b64-cluster-ca $B64_CLUSTER_CA --apiserver-endpoint $API_SERVER_URL --dns-cluster-ip $K8S_CLUSTER_DNS_IP 

--//--

Resource Specs and Logs

Karpenter Logs (lunching node in 11:27:02.675):

2022-12-22T11:17:38.032Z	DEBUG	Successfully created the logger.
2022-12-22T11:17:38.032Z	DEBUG	Logging level set to: debug
{"level":"info","ts":1671707858.0355446,"logger":"fallback","caller":"injection/injection.go:63","msg":"Starting informers..."}
2022-12-22T11:17:38.135Z	DEBUG	controller	waiting for configmaps	{"commit": "f60dacd", "configmaps": ["karpenter-global-settings"]}
2022-12-22T11:17:38.639Z	DEBUG	controller	karpenter-global-settings config "karpenter-global-settings" config was added or updated: settings.Settings{BatchMaxDuration:v1.Duration{Duration:10000000000}, BatchIdleDuration:v1.Duration{Duration:1000000000}}	{"commit": "f60dacd"}
2022-12-22T11:17:38.639Z	DEBUG	controller	karpenter-global-settings config "karpenter-global-settings" config was added or updated: settings.Settings{ClusterName:"eks-dev", ClusterEndpoint:"https://5CB5A2BEA0EC2C64E4CD95AF23947A97.yl4.eu-west-1.eks.amazonaws.com", DefaultInstanceProfile:"Karpenter-eks-dev-20221218174041557300000001", EnablePodENI:false, EnableENILimitedPodDensity:true, IsolatedVPC:false, NodeNameConvention:"ip-name", VMMemoryOverheadPercent:0.075, InterruptionQueueName:"Karpenter-eks-dev", Tags:map[string]string{}}	{"commit": "f60dacd"}
2022-12-22T11:17:38.770Z	DEBUG	controller.aws	discovered region	{"commit": "f60dacd", "region": "eu-west-1"}
2022-12-22T11:17:38.777Z	DEBUG	controller.aws	discovered kube dns	{"commit": "f60dacd", "kube-dns-ip": "172.20.0.10"}
2022/12/22 11:17:38 Registering 2 clients
2022/12/22 11:17:38 Registering 2 informer factories
2022/12/22 11:17:38 Registering 3 informers
2022/12/22 11:17:38 Registering 6 controllers
2022-12-22T11:17:38.968Z	DEBUG	controller.aws	discovered version	{"commit": "f60dacd", "version": "v0.20.0"}
2022-12-22T11:17:38.970Z	INFO	controller	Starting server	{"commit": "f60dacd", "path": "/metrics", "kind": "metrics", "addr": "[::]:8080"}
2022-12-22T11:17:38.970Z	INFO	controller	Starting server	{"commit": "f60dacd", "kind": "health probe", "addr": "[::]:8081"}
I1222 11:17:39.071776       1 leaderelection.go:248] attempting to acquire leader lease karpenter/karpenter-leader-election...
2022-12-22T11:17:39.097Z	INFO	controller	Starting informers...	{"commit": "f60dacd"}
2022-12-22T11:17:39.341Z	INFO	controller.aws.pricing	updated spot pricing with instance types and offerings	{"commit": "f60dacd", "instance-type-count": 607, "offering-count": 1680}
2022-12-22T11:17:41.473Z	INFO	controller.aws.pricing	updated on-demand pricing	{"commit": "f60dacd", "instance-type-count": 595}
I1222 11:17:56.062762       1 leaderelection.go:258] successfully acquired lease karpenter/karpenter-leader-election
2022-12-22T11:17:56.062Z	INFO	controller.provisioner	starting controller	{"commit": "f60dacd"}
2022-12-22T11:17:56.063Z	INFO	controller.deprovisioning	starting controller	{"commit": "f60dacd"}
2022-12-22T11:17:56.063Z	INFO	controller.metricscraper	starting controller	{"commit": "f60dacd"}
2022-12-22T11:17:56.063Z	INFO	controller	Starting EventSource	{"commit": "f60dacd", "controller": "node-state", "controllerGroup": "", "controllerKind": "Node", "source": "kind source: *v1.Node"}
2022-12-22T11:17:56.063Z	INFO	controller	Starting Controller	{"commit": "f60dacd", "controller": "node-state", "controllerGroup": "", "controllerKind": "Node"}
2022-12-22T11:17:56.064Z	INFO	controller	Starting EventSource	{"commit": "f60dacd", "controller": "provisioning", "controllerGroup": "", "controllerKind": "Pod", "source": "kind source: *v1.Pod"}
2022-12-22T11:17:56.064Z	INFO	controller	Starting Controller	{"commit": "f60dacd", "controller": "provisioning", "controllerGroup": "", "controllerKind": "Pod"}
2022-12-22T11:17:56.064Z	INFO	controller	Starting EventSource	{"commit": "f60dacd", "controller": "provisionerstate", "controllerGroup": "karpenter.sh", "controllerKind": "Provisioner", "source": "kind source: *v1alpha5.Provisioner"}
2022-12-22T11:17:56.064Z	INFO	controller	Starting Controller	{"commit": "f60dacd", "controller": "provisionerstate", "controllerGroup": "karpenter.sh", "controllerKind": "Provisioner"}
2022-12-22T11:17:56.065Z	INFO	controller	Starting EventSource	{"commit": "f60dacd", "controller": "pod-state", "controllerGroup": "", "controllerKind": "Pod", "source": "kind source: *v1.Pod"}
2022-12-22T11:17:56.065Z	INFO	controller	Starting Controller	{"commit": "f60dacd", "controller": "pod-state", "controllerGroup": "", "controllerKind": "Pod"}
2022-12-22T11:17:56.065Z	INFO	controller	Starting EventSource	{"commit": "f60dacd", "controller": "termination", "controllerGroup": "", "controllerKind": "Node", "source": "kind source: *v1.Node"}
2022-12-22T11:17:56.065Z	INFO	controller	Starting Controller	{"commit": "f60dacd", "controller": "termination", "controllerGroup": "", "controllerKind": "Node"}
2022-12-22T11:17:56.066Z	INFO	controller	Starting EventSource	{"commit": "f60dacd", "controller": "node", "controllerGroup": "", "controllerKind": "Node", "source": "kind source: *v1.Node"}
2022-12-22T11:17:56.066Z	INFO	controller	Starting EventSource	{"commit": "f60dacd", "controller": "node", "controllerGroup": "", "controllerKind": "Node", "source": "kind source: *v1alpha5.Provisioner"}
2022-12-22T11:17:56.066Z	INFO	controller	Starting EventSource	{"commit": "f60dacd", "controller": "node", "controllerGroup": "", "controllerKind": "Node", "source": "kind source: *v1.Pod"}
2022-12-22T11:17:56.066Z	INFO	controller	Starting EventSource	{"commit": "f60dacd", "controller": "node", "controllerGroup": "", "controllerKind": "Node", "source": "channel source: 0xc000d9ba90"}
2022-12-22T11:17:56.066Z	INFO	controller	Starting Controller	{"commit": "f60dacd", "controller": "node", "controllerGroup": "", "controllerKind": "Node"}
2022-12-22T11:17:56.066Z	INFO	controller	Starting EventSource	{"commit": "f60dacd", "controller": "provisionermetrics", "controllerGroup": "karpenter.sh", "controllerKind": "Provisioner", "source": "kind source: *v1alpha5.Provisioner"}
2022-12-22T11:17:56.066Z	INFO	controller	Starting Controller	{"commit": "f60dacd", "controller": "provisionermetrics", "controllerGroup": "karpenter.sh", "controllerKind": "Provisioner"}
2022-12-22T11:17:56.066Z	INFO	controller	Starting EventSource	{"commit": "f60dacd", "controller": "podmetrics", "controllerGroup": "", "controllerKind": "Pod", "source": "kind source: *v1.Pod"}
2022-12-22T11:17:56.066Z	INFO	controller	Starting Controller	{"commit": "f60dacd", "controller": "podmetrics", "controllerGroup": "", "controllerKind": "Pod"}
2022-12-22T11:17:56.066Z	INFO	controller	Starting EventSource	{"commit": "f60dacd", "controller": "inflightchecks", "controllerGroup": "", "controllerKind": "Node", "source": "kind source: *v1.Node"}
2022-12-22T11:17:56.066Z	INFO	controller	Starting Controller	{"commit": "f60dacd", "controller": "inflightchecks", "controllerGroup": "", "controllerKind": "Node"}
2022-12-22T11:17:56.066Z	INFO	controller	Starting EventSource	{"commit": "f60dacd", "controller": "counter", "controllerGroup": "karpenter.sh", "controllerKind": "Provisioner", "source": "kind source: *v1alpha5.Provisioner"}
2022-12-22T11:17:56.067Z	INFO	controller	Starting EventSource	{"commit": "f60dacd", "controller": "counter", "controllerGroup": "karpenter.sh", "controllerKind": "Provisioner", "source": "kind source: *v1.Node"}
2022-12-22T11:17:56.067Z	INFO	controller	Starting Controller	{"commit": "f60dacd", "controller": "counter", "controllerGroup": "karpenter.sh", "controllerKind": "Provisioner"}
2022-12-22T11:17:56.067Z	INFO	controller.interruption	starting controller	{"commit": "f60dacd"}
2022-12-22T11:17:56.067Z	DEBUG	controller.interruption	watching interruption queue	{"commit": "f60dacd", "queue": "Karpenter-eks-dev"}
2022-12-22T11:17:56.067Z	DEBUG	controller.aws	hydrating the launch template cache	{"commit": "f60dacd", "tag-key": "karpenter.k8s.aws/cluster", "tag-value": "eks-dev"}
2022-12-22T11:17:56.117Z	DEBUG	controller.aws	finished hydrating the launch template cache	{"commit": "f60dacd", "tag-key": "karpenter.k8s.aws/cluster", "tag-value": "eks-dev", "item-count": 0}
2022-12-22T11:17:56.165Z	INFO	controller	Starting workers	{"commit": "f60dacd", "controller": "provisioning", "controllerGroup": "", "controllerKind": "Pod", "worker count": 10}
2022-12-22T11:17:56.165Z	INFO	controller	Starting workers	{"commit": "f60dacd", "controller": "pod-state", "controllerGroup": "", "controllerKind": "Pod", "worker count": 10}
2022-12-22T11:17:56.264Z	INFO	controller	Starting workers	{"commit": "f60dacd", "controller": "podmetrics", "controllerGroup": "", "controllerKind": "Pod", "worker count": 1}
2022-12-22T11:17:56.364Z	INFO	controller	Starting workers	{"commit": "f60dacd", "controller": "node-state", "controllerGroup": "", "controllerKind": "Node", "worker count": 10}
2022-12-22T11:17:56.364Z	INFO	controller	Starting workers	{"commit": "f60dacd", "controller": "node", "controllerGroup": "", "controllerKind": "Node", "worker count": 10}
2022-12-22T11:17:56.372Z	INFO	controller	Starting workers	{"commit": "f60dacd", "controller": "termination", "controllerGroup": "", "controllerKind": "Node", "worker count": 10}
2022-12-22T11:17:56.388Z	INFO	controller	Starting workers	{"commit": "f60dacd", "controller": "provisionermetrics", "controllerGroup": "karpenter.sh", "controllerKind": "Provisioner", "worker count": 1}
2022-12-22T11:17:56.397Z	INFO	controller	Starting workers	{"commit": "f60dacd", "controller": "provisionerstate", "controllerGroup": "karpenter.sh", "controllerKind": "Provisioner", "worker count": 10}
2022-12-22T11:17:56.398Z	INFO	controller	Starting workers	{"commit": "f60dacd", "controller": "inflightchecks", "controllerGroup": "", "controllerKind": "Node", "worker count": 10}
2022-12-22T11:17:56.403Z	INFO	controller	Starting workers	{"commit": "f60dacd", "controller": "counter", "controllerGroup": "karpenter.sh", "controllerKind": "Provisioner", "worker count": 10}
2022-12-22T11:17:57.505Z	DEBUG	controller.deprovisioning	discovered EC2 instance types	{"commit": "f60dacd", "instance-type-count": 588}
2022-12-22T11:17:57.578Z	DEBUG	controller.deprovisioning	discovered subnets	{"commit": "f60dacd", "subnets": ["subnet-a59be2fe (eu-west-1a)", "subnet-b26a6bfb (eu-west-1c)", "subnet-803f03e7 (eu-west-1b)"]}
2022-12-22T11:17:57.724Z	DEBUG	controller.deprovisioning	discovered EC2 instance types zonal offerings for subnets	{"commit": "f60dacd", "subnet-selector": "{\"aws-ids\":\"subnet-a59be2fe, subnet-803f03e7, subnet-b26a6bfb\"}"}
2022-12-22T11:17:57.887Z	INFO	controller.inflightchecks	Inflight check failed for node, Expected 20Gi of resource ephemeral-storage, but found 10473452Ki (49.9% of expected)	{"commit": "f60dacd", "node": "ip-10-2-20-144.eu-west-1.compute.internal"}
2022-12-22T11:17:57.908Z	INFO	controller.inflightchecks	Inflight check failed for node, Expected 20Gi of resource ephemeral-storage, but found 10473452Ki (49.9% of expected)	{"commit": "f60dacd", "node": "ip-10-2-25-170.eu-west-1.compute.internal"}
2022-12-22T11:17:58.480Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:17:59.034Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:18:09.707Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:18:10.352Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:18:20.951Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:18:21.509Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:18:32.136Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:18:32.671Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:18:43.252Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:18:43.878Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:18:54.436Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:18:55.186Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:18:56.231Z	INFO	controller.provisioner	found provisionable pod(s)	{"commit": "f60dacd", "pods": 1}
2022-12-22T11:18:56.231Z	INFO	controller.provisioner	computed new node(s) to fit pod(s)	{"commit": "f60dacd", "nodes": 1, "pods": 1}
2022-12-22T11:18:56.234Z	INFO	controller.provisioner	launching node with 1 pods requesting {"cpu":"1325m","memory":"2007081728","pods":"5"} from types c6gn.large, c6g.large, c6gd.large, c7g.large, m6gd.large and 57 other(s)	{"commit": "f60dacd", "provisioner": "arm"}
2022-12-22T11:18:58.366Z	INFO	controller.provisioner.cloudprovider	launched new instance	{"commit": "f60dacd", "provisioner": "arm", "launched-instance": "i-0cab0c7c6e9fa1785", "hostname": "ip-10-2-22-17.eu-west-1.compute.internal", "type": "c6gd.large", "zone": "eu-west-1b", "capacity-type": "spot"}
2022-12-22T11:19:05.820Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:19:06.381Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:20:30.778Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:23:07.864Z	DEBUG	controller.deprovisioning	discovered EC2 instance types	{"commit": "f60dacd", "instance-type-count": 588}
2022-12-22T11:25:35.029Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:27:01.221Z	INFO	controller.termination	cordoned node	{"commit": "f60dacd", "node": "ip-10-2-22-17.eu-west-1.compute.internal"}
2022-12-22T11:27:02.666Z	INFO	controller.provisioner	found provisionable pod(s)	{"commit": "f60dacd", "pods": 1}
2022-12-22T11:27:02.666Z	INFO	controller.provisioner	computed new node(s) to fit pod(s)	{"commit": "f60dacd", "nodes": 1, "pods": 1}
2022-12-22T11:27:02.675Z	INFO	controller.provisioner	launching node with 1 pods requesting {"cpu":"1325m","memory":"2007081728","pods":"5"} from types c6gd.large, c6gn.large, c6g.large, c7g.large, m6g.large and 57 other(s)	{"commit": "f60dacd", "provisioner": "arm"}
2022-12-22T11:27:05.271Z	INFO	controller.provisioner.cloudprovider	launched new instance	{"commit": "f60dacd", "provisioner": "arm", "launched-instance": "i-02ed0c4c15274fc20", "hostname": "ip-10-2-23-188.eu-west-1.compute.internal", "type": "c6gd.large", "zone": "eu-west-1b", "capacity-type": "spot"}
2022-12-22T11:27:40.624Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:27:41.165Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:27:43.497Z	INFO	controller.termination	deleted node	{"commit": "f60dacd", "node": "ip-10-2-22-17.eu-west-1.compute.internal"}
2022-12-22T11:27:51.946Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:27:52.514Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:27:56.457Z	INFO	controller.inflightchecks	Inflight check failed for node, Expected 20Gi of resource ephemeral-storage, but found 10473452Ki (49.9% of expected)	{"commit": "f60dacd", "node": "ip-10-2-20-144.eu-west-1.compute.internal"}
2022-12-22T11:27:56.543Z	INFO	controller.inflightchecks	Inflight check failed for node, Expected 20Gi of resource ephemeral-storage, but found 10473452Ki (49.9% of expected)	{"commit": "f60dacd", "node": "ip-10-2-25-170.eu-west-1.compute.internal"}
2022-12-22T11:28:03.206Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:28:03.853Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:28:15.116Z	DEBUG	controller.deprovisioning	discovered EC2 instance types	{"commit": "f60dacd", "instance-type-count": 588}
2022-12-22T11:28:27.169Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:28:38.839Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}
2022-12-22T11:29:00.634Z	DEBUG	controller.deprovisioning	relaxing soft constraints for pod since it previously failed to schedule, removing: spec.affinity.podAffinity.preferredDuringSchedulingIgnoredDuringExecution[0]={"weight":100,"podAffinityTerm":{"labelSelector":{"matchLabels":{"app.kubernetes.io/name":"kube-state-metrics"}},"topologyKey":"kubernetes.io/hostname"}}	{"commit": "f60dacd", "pod": "newrelic/newrelic-bundle-nrk8s-ksm-6b7f676f76-scbs8"}

kube-proxy:

I1222 11:27:58.975278       1 flags.go:64] FLAG: --add-dir-header="false"
I1222 11:27:58.975342       1 flags.go:64] FLAG: --alsologtostderr="false"
I1222 11:27:58.975351       1 flags.go:64] FLAG: --bind-address="0.0.0.0"
I1222 11:27:58.975356       1 flags.go:64] FLAG: --bind-address-hard-fail="false"
I1222 11:27:58.975361       1 flags.go:64] FLAG: --boot-id-file="/proc/sys/kernel/random/boot_id"
I1222 11:27:58.975365       1 flags.go:64] FLAG: --cleanup="false"
I1222 11:27:58.975368       1 flags.go:64] FLAG: --cluster-cidr=""
I1222 11:27:58.975372       1 flags.go:64] FLAG: --config="/var/lib/kube-proxy-config/config"
I1222 11:27:58.975376       1 flags.go:64] FLAG: --config-sync-period="15m0s"
I1222 11:27:58.975384       1 flags.go:64] FLAG: --conntrack-max-per-core="32768"
I1222 11:27:58.975389       1 flags.go:64] FLAG: --conntrack-min="131072"
I1222 11:27:58.975393       1 flags.go:64] FLAG: --conntrack-tcp-timeout-close-wait="1h0m0s"
I1222 11:27:58.975396       1 flags.go:64] FLAG: --conntrack-tcp-timeout-established="24h0m0s"
I1222 11:27:58.975399       1 flags.go:64] FLAG: --detect-local-mode=""
I1222 11:27:58.975403       1 flags.go:64] FLAG: --feature-gates=""
I1222 11:27:58.975415       1 flags.go:64] FLAG: --healthz-bind-address="0.0.0.0:10256"
I1222 11:27:58.975420       1 flags.go:64] FLAG: --healthz-port="10256"
I1222 11:27:58.975423       1 flags.go:64] FLAG: --help="false"
I1222 11:27:58.975426       1 flags.go:64] FLAG: --hostname-override=""
I1222 11:27:58.975429       1 flags.go:64] FLAG: --iptables-masquerade-bit="14"
I1222 11:27:58.975432       1 flags.go:64] FLAG: --iptables-min-sync-period="1s"
I1222 11:27:58.975435       1 flags.go:64] FLAG: --iptables-sync-period="30s"
I1222 11:27:58.975442       1 flags.go:64] FLAG: --ipvs-exclude-cidrs="[]"
I1222 11:27:58.975448       1 flags.go:64] FLAG: --ipvs-min-sync-period="0s"
I1222 11:27:58.975451       1 flags.go:64] FLAG: --ipvs-scheduler=""
I1222 11:27:58.975455       1 flags.go:64] FLAG: --ipvs-strict-arp="false"
I1222 11:27:58.975458       1 flags.go:64] FLAG: --ipvs-sync-period="30s"
I1222 11:27:58.975464       1 flags.go:64] FLAG: --ipvs-tcp-timeout="0s"
I1222 11:27:58.975467       1 flags.go:64] FLAG: --ipvs-tcpfin-timeout="0s"
I1222 11:27:58.975470       1 flags.go:64] FLAG: --ipvs-udp-timeout="0s"
I1222 11:27:58.975476       1 flags.go:64] FLAG: --kube-api-burst="10"
I1222 11:27:58.975479       1 flags.go:64] FLAG: --kube-api-content-type="application/vnd.kubernetes.protobuf"
I1222 11:27:58.975483       1 flags.go:64] FLAG: --kube-api-qps="5"
I1222 11:27:58.975488       1 flags.go:64] FLAG: --kubeconfig=""
I1222 11:27:58.975491       1 flags.go:64] FLAG: --log-backtrace-at=":0"
I1222 11:27:58.975496       1 flags.go:64] FLAG: --log-dir=""
I1222 11:27:58.975502       1 flags.go:64] FLAG: --log-file=""
I1222 11:27:58.975505       1 flags.go:64] FLAG: --log-file-max-size="1800"
I1222 11:27:58.975509       1 flags.go:64] FLAG: --log-flush-frequency="5s"
I1222 11:27:58.975512       1 flags.go:64] FLAG: --logtostderr="true"
I1222 11:27:58.975515       1 flags.go:64] FLAG: --machine-id-file="/etc/machine-id,/var/lib/dbus/machine-id"
I1222 11:27:58.975519       1 flags.go:64] FLAG: --masquerade-all="false"
I1222 11:27:58.975522       1 flags.go:64] FLAG: --master=""
I1222 11:27:58.975527       1 flags.go:64] FLAG: --metrics-bind-address="127.0.0.1:10249"
I1222 11:27:58.975531       1 flags.go:64] FLAG: --metrics-port="10249"
I1222 11:27:58.975534       1 flags.go:64] FLAG: --nodeport-addresses="[]"
I1222 11:27:58.975543       1 flags.go:64] FLAG: --one-output="false"
I1222 11:27:58.975546       1 flags.go:64] FLAG: --oom-score-adj="-999"
I1222 11:27:58.975549       1 flags.go:64] FLAG: --profiling="false"
I1222 11:27:58.975553       1 flags.go:64] FLAG: --proxy-mode=""
I1222 11:27:58.975560       1 flags.go:64] FLAG: --proxy-port-range=""
I1222 11:27:58.975564       1 flags.go:64] FLAG: --show-hidden-metrics-for-version=""
I1222 11:27:58.975567       1 flags.go:64] FLAG: --skip-headers="false"
I1222 11:27:58.975570       1 flags.go:64] FLAG: --skip-log-headers="false"
I1222 11:27:58.975573       1 flags.go:64] FLAG: --stderrthreshold="2"
I1222 11:27:58.975576       1 flags.go:64] FLAG: --udp-timeout="250ms"
I1222 11:27:58.975580       1 flags.go:64] FLAG: --v="2"
I1222 11:27:58.975583       1 flags.go:64] FLAG: --version="false"
I1222 11:27:58.975591       1 flags.go:64] FLAG: --vmodule=""
I1222 11:27:58.975594       1 flags.go:64] FLAG: --write-config-to=""
I1222 11:27:58.976964       1 server.go:436] "Using lenient decoding as strict decoding failed" err="strict decoding error: unknown field \"max\", unknown field \"resourceContainer\""
I1222 11:27:58.977108       1 feature_gate.go:245] feature gates: &{map[]}
I1222 11:27:58.977190       1 feature_gate.go:245] feature gates: &{map[]}
I1222 11:27:59.013551       1 node.go:163] Successfully retrieved node IP: 10.2.23.188
I1222 11:27:59.013587       1 server_others.go:138] "Detected node IP" address="10.2.23.188"
I1222 11:27:59.013793       1 server_others.go:175] "DetectLocalMode" LocalMode="ClusterCIDR"
I1222 11:27:59.017211       1 server_others.go:206] "Using iptables Proxier"
I1222 11:27:59.017239       1 server_others.go:213] "kube-proxy running in dual-stack mode" ipFamily=IPv4
I1222 11:27:59.017250       1 server_others.go:214] "Creating dualStackProxier for iptables"
I1222 11:27:59.017257       1 server_others.go:475] "Detect-local-mode set to ClusterCIDR, but no cluster CIDR defined"
I1222 11:27:59.017270       1 server_others.go:524] "Defaulting to no-op detect-local" detect-local-mode="ClusterCIDR"
I1222 11:27:59.017332       1 utils.go:400] "Changed sysctl" name="net/ipv4/conf/all/route_localnet" before=0 after=1
I1222 11:27:59.017364       1 proxier.go:280] "Using iptables mark for masquerade" ipFamily=IPv4 mark="0x00004000"
I1222 11:27:59.017388       1 proxier.go:324] "Iptables sync params" ipFamily=IPv4 minSyncPeriod="1s" syncPeriod="30s" burstSyncs=2
I1222 11:27:59.017410       1 proxier.go:334] "Iptables supports --random-fully" ipFamily=IPv4
I1222 11:27:59.017436       1 proxier.go:280] "Using iptables mark for masquerade" ipFamily=IPv6 mark="0x00004000"
I1222 11:27:59.017451       1 proxier.go:324] "Iptables sync params" ipFamily=IPv6 minSyncPeriod="1s" syncPeriod="30s" burstSyncs=2
I1222 11:27:59.017462       1 proxier.go:334] "Iptables supports --random-fully" ipFamily=IPv6
I1222 11:27:59.017624       1 server.go:656] "Version info" version="v1.23.7-eks-fba872d"
I1222 11:27:59.018130       1 sysinfo.go:232] Found node without cache information, nodeDir: /sys/devices/system/node/node0
I1222 11:27:59.018341       1 conntrack.go:100] "Set sysctl" entry="net/netfilter/nf_conntrack_max" value=131072
I1222 11:27:59.018409       1 conntrack.go:52] "Setting nf_conntrack_max" nf_conntrack_max=131072
I1222 11:27:59.018570       1 mount_linux.go:208] Detected OS without systemd
I1222 11:27:59.018809       1 conntrack.go:83] "Setting conntrack hashsize" conntrack hashsize=32768
I1222 11:27:59.031804       1 conntrack.go:100] "Set sysctl" entry="net/netfilter/nf_conntrack_tcp_timeout_close_wait" value=3600
I1222 11:27:59.031981       1 config.go:226] "Starting endpoint slice config controller"
I1222 11:27:59.032061       1 shared_informer.go:240] Waiting for caches to sync for endpoint slice config
I1222 11:27:59.032147       1 config.go:317] "Starting service config controller"
I1222 11:27:59.032216       1 shared_informer.go:240] Waiting for caches to sync for service config
I1222 11:27:59.034421       1 service.go:304] "Service updated ports" service="applications/k8s-message-hub" portCount=1
I1222 11:27:59.034454       1 service.go:304] "Service updated ports" service="applications/kafka" portCount=1
I1222 11:27:59.034470       1 service.go:304] "Service updated ports" service="default/kubernetes" portCount=1
I1222 11:27:59.034484       1 service.go:304] "Service updated ports" service="fargate/practicom" portCount=1
I1222 11:27:59.034500       1 service.go:304] "Service updated ports" service="kube-system/kubernetes-dashboard" portCount=1
I1222 11:27:59.034526       1 service.go:304] "Service updated ports" service="kubernetes-dashboard/kubernetes-dashboard" portCount=1
I1222 11:27:59.034546       1 service.go:304] "Service updated ports" service="newrelic/newrelic-bundle-kube-state-metrics" portCount=1
I1222 11:27:59.034562       1 service.go:304] "Service updated ports" service="applications/sample-2" portCount=1
I1222 11:27:59.034575       1 service.go:304] "Service updated ports" service="fargate/optima" portCount=1
I1222 11:27:59.034605       1 service.go:304] "Service updated ports" service="fargate/redis-load-tester" portCount=1
I1222 11:27:59.034620       1 service.go:304] "Service updated ports" service="kube-system/cluster-autoscaler-aws-cluster-autoscaler" portCount=1
I1222 11:27:59.034634       1 service.go:304] "Service updated ports" service="kubernetes-dashboard/dashboard-metrics-scraper" portCount=1
I1222 11:27:59.034646       1 service.go:304] "Service updated ports" service="applications/sync-worker" portCount=1
I1222 11:27:59.034666       1 service.go:304] "Service updated ports" service="karpenter/karpenter" portCount=2
I1222 11:27:59.034688       1 service.go:304] "Service updated ports" service="kube-system/aws-load-balancer-webhook-service" portCount=1
I1222 11:27:59.034702       1 service.go:304] "Service updated ports" service="newrelic/newrelic-bundle-nri-metadata-injection" portCount=1
I1222 11:27:59.034715       1 service.go:304] "Service updated ports" service="fargate/fg-tabitorder" portCount=1
I1222 11:27:59.034728       1 service.go:304] "Service updated ports" service="fargate/optima-reports" portCount=1
I1222 11:27:59.034741       1 service.go:304] "Service updated ports" service="fargate/rosworker-fargate" portCount=1
I1222 11:27:59.034755       1 service.go:304] "Service updated ports" service="kube-system/heapster" portCount=1
I1222 11:27:59.034767       1 service.go:304] "Service updated ports" service="applications/k8-logzp" portCount=1
I1222 11:27:59.034785       1 service.go:304] "Service updated ports" service="applications/k8-shift-celery" portCount=1
I1222 11:27:59.034806       1 service.go:304] "Service updated ports" service="applications/k8-shift" portCount=1
I1222 11:27:59.034821       1 service.go:304] "Service updated ports" service="kube-system/monitoring-influxdb" portCount=1
I1222 11:27:59.034834       1 service.go:304] "Service updated ports" service="observability/simple-prod-query" portCount=1
I1222 11:27:59.034854       1 service.go:304] "Service updated ports" service="applications/sample" portCount=1
I1222 11:27:59.034880       1 service.go:304] "Service updated ports" service="kube-system/kube-dns" portCount=2
I1222 11:27:59.034894       1 service.go:304] "Service updated ports" service="kube-system/metrics-server" portCount=1
I1222 11:27:59.034920       1 service.go:304] "Service updated ports" service="observability/simple-prod-collector" portCount=4
I1222 11:27:59.034933       1 service.go:304] "Service updated ports" service="applications/k8-internus" portCount=1
I1222 11:27:59.034946       1 service.go:304] "Service updated ports" service="applications/k8-street-map" portCount=1
I1222 11:27:59.034965       1 service.go:304] "Service updated ports" service="applications/rosapi-dev" portCount=1
I1222 11:27:59.034978       1 service.go:304] "Service updated ports" service="fargate/sample" portCount=1
I1222 11:27:59.133127       1 shared_informer.go:247] Caches are synced for endpoint slice config 
I1222 11:27:59.133196       1 proxier.go:782] "Not syncing iptables until Services and Endpoints have been received from master"
I1222 11:27:59.133126       1 shared_informer.go:247] Caches are synced for service config 
I1222 11:27:59.133263       1 proxier.go:782] "Not syncing iptables until Services and Endpoints have been received from master"
I1222 11:27:59.133292       1 service.go:419] "Adding new service port" portName="kube-system/heapster" servicePort="172.20.202.128:80/TCP"
I1222 11:27:59.133310       1 service.go:419] "Adding new service port" portName="kubernetes-dashboard/kubernetes-dashboard" servicePort="172.20.221.116:443/TCP"
I1222 11:27:59.133323       1 service.go:419] "Adding new service port" portName="newrelic/newrelic-bundle-kube-state-metrics:http" servicePort="172.20.73.16:8080/TCP"
I1222 11:27:59.133335       1 service.go:419] "Adding new service port" portName="fargate/optima-reports:app" servicePort="172.20.141.112:80/TCP"
I1222 11:27:59.133353       1 service.go:419] "Adding new service port" portName="kube-system/kube-dns:dns" servicePort="172.20.0.10:53/UDP"
I1222 11:27:59.133364       1 service.go:419] "Adding new service port" portName="kube-system/kube-dns:dns-tcp" servicePort="172.20.0.10:53/TCP"
I1222 11:27:59.133374       1 service.go:419] "Adding new service port" portName="kube-system/metrics-server:https" servicePort="172.20.145.196:443/TCP"
I1222 11:27:59.133385       1 service.go:419] "Adding new service port" portName="applications/k8-street-map:app" servicePort="172.20.18.129:80/TCP"
I1222 11:27:59.133397       1 service.go:419] "Adding new service port" portName="default/kubernetes:https" servicePort="172.20.0.1:443/TCP"
I1222 11:27:59.133412       1 service.go:419] "Adding new service port" portName="applications/k8-logzp:app" servicePort="172.20.75.85:80/TCP"
I1222 11:27:59.133423       1 service.go:419] "Adding new service port" portName="applications/k8-internus:app" servicePort="172.20.9.226:80/TCP"
I1222 11:27:59.133433       1 service.go:419] "Adding new service port" portName="fargate/sample:app" servicePort="172.20.147.63:80/TCP"
I1222 11:27:59.133444       1 service.go:419] "Adding new service port" portName="kube-system/kubernetes-dashboard" servicePort="172.20.47.78:443/TCP"
I1222 11:27:59.133456       1 service.go:419] "Adding new service port" portName="kube-system/monitoring-influxdb" servicePort="172.20.91.146:8086/TCP"
I1222 11:27:59.133470       1 service.go:419] "Adding new service port" portName="observability/simple-prod-query:query" servicePort="172.20.7.165:16686/TCP"
I1222 11:27:59.133482       1 service.go:419] "Adding new service port" portName="observability/simple-prod-collector:c-binary-trft" servicePort="172.20.57.110:14268/TCP"
I1222 11:27:59.133495       1 service.go:419] "Adding new service port" portName="observability/simple-prod-collector:zipkin" servicePort="172.20.57.110:9411/TCP"
I1222 11:27:59.133505       1 service.go:419] "Adding new service port" portName="observability/simple-prod-collector:grpc" servicePort="172.20.57.110:14250/TCP"
I1222 11:27:59.133515       1 service.go:419] "Adding new service port" portName="observability/simple-prod-collector:c-tchan-trft" servicePort="172.20.57.110:14267/TCP"
I1222 11:27:59.133526       1 service.go:419] "Adding new service port" portName="applications/k8s-message-hub:app" servicePort="172.20.42.160:80/TCP"
I1222 11:27:59.133538       1 service.go:419] "Adding new service port" portName="karpenter/karpenter:http-metrics" servicePort="172.20.114.42:8080/TCP"
I1222 11:27:59.133549       1 service.go:419] "Adding new service port" portName="karpenter/karpenter:https-webhook" servicePort="172.20.114.42:443/TCP"
I1222 11:27:59.133562       1 service.go:419] "Adding new service port" portName="kube-system/aws-load-balancer-webhook-service:webhook-server" servicePort="172.20.189.40:443/TCP"
I1222 11:27:59.133572       1 service.go:419] "Adding new service port" portName="applications/k8-shift-celery:app" servicePort="172.20.23.55:80/TCP"
I1222 11:27:59.133585       1 service.go:419] "Adding new service port" portName="applications/k8-shift:app" servicePort="172.20.5.123:80/TCP"
I1222 11:27:59.133597       1 service.go:419] "Adding new service port" portName="applications/rosapi-dev:app" servicePort="172.20.129.208:80/TCP"
I1222 11:27:59.133610       1 service.go:419] "Adding new service port" portName="applications/kafka:app" servicePort="172.20.252.248:80/TCP"
I1222 11:27:59.133624       1 service.go:419] "Adding new service port" portName="applications/sample-2:app" servicePort="172.20.113.108:80/TCP"
I1222 11:27:59.133637       1 service.go:419] "Adding new service port" portName="fargate/optima:app" servicePort="172.20.21.153:80/TCP"
I1222 11:27:59.133652       1 service.go:419] "Adding new service port" portName="fargate/redis-load-tester:app" servicePort="172.20.198.23:80/TCP"
I1222 11:27:59.133663       1 service.go:419] "Adding new service port" portName="kubernetes-dashboard/dashboard-metrics-scraper" servicePort="172.20.93.243:8000/TCP"
I1222 11:27:59.133675       1 service.go:419] "Adding new service port" portName="applications/sync-worker:app" servicePort="172.20.224.148:80/TCP"
I1222 11:27:59.133686       1 service.go:419] "Adding new service port" portName="newrelic/newrelic-bundle-nri-metadata-injection" servicePort="172.20.43.160:443/TCP"
I1222 11:27:59.133696       1 service.go:419] "Adding new service port" portName="fargate/practicom:app" servicePort="172.20.83.31:80/TCP"
I1222 11:27:59.133707       1 service.go:419] "Adding new service port" portName="fargate/rosworker-fargate:app" servicePort="172.20.88.100:80/TCP"
I1222 11:27:59.133718       1 service.go:419] "Adding new service port" portName="fargate/fg-tabitorder:app" servicePort="172.20.74.83:80/TCP"
I1222 11:27:59.133729       1 service.go:419] "Adding new service port" portName="applications/sample:app" servicePort="172.20.216.207:80/TCP"
I1222 11:27:59.133754       1 service.go:419] "Adding new service port" portName="kube-system/cluster-autoscaler-aws-cluster-autoscaler:http" servicePort="172.20.70.233:8085/TCP"
I1222 11:27:59.134016       1 proxier.go:807] "Stale service" protocol="udp" servicePortName="kube-system/kube-dns:dns" clusterIP="172.20.0.10"
I1222 11:27:59.134023       1 proxier.go:823] "Syncing iptables rules"
I1222 11:27:59.186084       1 proxier.go:790] "SyncProxyRules complete" elapsed="52.832323ms"
I1222 11:27:59.186107       1 proxier.go:823] "Syncing iptables rules"
I1222 11:27:59.213728       1 proxier.go:790] "SyncProxyRules complete" elapsed="27.604593ms"
I1222 11:29:20.182334       1 proxier.go:823] "Syncing iptables rules"
I1222 11:29:20.241245       1 proxier.go:790] "SyncProxyRules complete" elapsed="69.137817ms"
I1222 11:29:47.107778       1 proxier.go:823] "Syncing iptables rules"
I1222 11:29:47.134222       1 proxier.go:790] "SyncProxyRules complete" elapsed="26.489282ms"

{"level":"info","ts":"2022-12-22T11:28:20.326Z","caller":"entrypoint.sh","msg":"Validating env variables ..."}
{"level":"info","ts":"2022-12-22T11:28:20.327Z","caller":"entrypoint.sh","msg":"Install CNI binaries.."}
{"level":"info","ts":"2022-12-22T11:28:20.338Z","caller":"entrypoint.sh","msg":"Starting IPAM daemon in the background ... "}
{"level":"info","ts":"2022-12-22T11:28:20.339Z","caller":"entrypoint.sh","msg":"Checking for IPAM connectivity ... "}
{"level":"info","ts":"2022-12-22T11:28:21.344Z","caller":"entrypoint.sh","msg":"Retrying waiting for IPAM-D"}
{"level":"info","ts":"2022-12-22T11:28:22.349Z","caller":"entrypoint.sh","msg":"Retrying waiting for IPAM-D"}
{"level":"info","ts":"2022-12-22T11:28:22.365Z","caller":"entrypoint.sh","msg":"Copying config file ... "}
{"level":"info","ts":"2022-12-22T11:28:22.369Z","caller":"entrypoint.sh","msg":"Successfully copied CNI plugin binary and config file."}
{"level":"info","ts":"2022-12-22T11:28:22.370Z","caller":"entrypoint.sh","msg":"Foregrounding IPAM daemon ..."}

Community Note

Please vote on this issue by adding a 👍 reaction to the original issue to help the community and maintainers prioritize this request
Please do not leave "+1" or "me too" comments, they generate extra noise for issue followers and do not help prioritize the request
If you are interested in working on this issue or have submitted a pull request, please leave a comment

The text was updated successfully, but these errors were encountered:

royb-tabit · 2022-12-22T11:52:45Z

EC2 logs:

ec2 logs:

 0000D4 (v02 AMAZON AMZNPPTT 00000001 AMZN 00000001)
[    0.000000] ACPI: SPCR: console: uart,mmio,0x90a0000,115200
[    0.000000] ACPI: NUMA: Failed to initialise from firmware
[    0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x00000004b9ffffff]
[    0.000000] NUMA: NODE_DATA [mem 0x4b982a800-0x4b982bfff]
[    0.000000] Zone ranges:
[    0.000000]   DMA32    [mem 0x0000000040000000-0x00000000ffffffff]
[    0.000000]   Normal   [mem 0x0000000100000000-0x00000004b9ffffff]
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000040000000-0x00000000786effff]
[    0.000000]   node   0: [mem 0x00000000786f0000-0x000000007872ffff]
[    0.000000]   node   0: [mem 0x0000000078730000-0x000000007bbfffff]
[    0.000000]   node   0: [mem 0x000000007bc00000-0x000000007bfdffff]
[    0.000000]   node   0: [mem 0x000000007bfe0000-0x000000007fffffff]
[    0.000000]   node   0: [mem 0x0000000400000000-0x00000004b9ffffff]
[    0.000000] Zeroed struct page in unavailable ranges: 64 pages
[    0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x00000004b9ffffff]
[    0.000000] psci: probing for conduit method from ACPI.
[    0.000000] psci: PSCIv1.0 detected in firmware.
[    0.000000] psci: Using standard PSCI v0.2 function IDs
[    0.000000] psci: Trusted OS migration not required
[    0.000000] psci: SMC Calling Convention v1.1
[    0.000000] ACPI: SRAT not present
[    0.000000] percpu: Embedded 32 pages/cpu s93144 r8192 d29736 u131072
[    0.000000] Detected PIPT I-cache on CPU0
[    0.000000] CPU features: detected: GIC system register CPU interface
[    0.000000] CPU features: detected: Hardware dirty bit management
[    0.000000] CPU features: detected: Speculative Store Bypassing Safe (SSBS)
[    0.000000] CPU features: detected: ARM erratum 1418040
[    0.000000] CPU features: detected: ARM erratum 1542419 (kernel portion)
[    0.000000] CPU features: detected: Spectre-BHB
[    0.000000] Fallback order for Node 0: 0 
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 1008000
[    0.000000] Policy zone: Normal
[    0.000000] Kernel command line: BOOT_IMAGE=/boot/vmlinuz-5.4.219-126.411.amzn2.aarch64 root=UUID=8e2e8eec-62db-4f3c-98c9-cac9f4c74f58 ro console=tty0 console=ttyS0,115200n8 net.ifnames=0 biosdevname=0 nvme_core.io_timeout=4294967295 rd.emergency=poweroff rd.shell=0 LANG=en_US.UTF-8 KEYTABLE=us
[    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)
[    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] software IO TLB: mapped [mem 0x71d20000-0x75d20000] (64MB)
[    0.000000] Memory: 3838764K/4096000K available (11964K kernel code, 1806K rwdata, 7316K rodata, 1408K init, 8800K bss, 191700K reserved, 65536K cma-reserved)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[    0.000000] ftrace: allocating 37352 entries in 146 pages
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000] rcu: 	RCU restricting CPUs from NR_CPUS=4096 to nr_cpu_ids=2.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2
[    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0
[    0.000000] GICv3: 96 SPIs implemented
[    0.000000] GICv3: 0 Extended SPIs implemented
[    0.000000] GICv3: Distributor has no Range Selector support
[    0.000000] GICv3: 16 PPIs implemented
[    0.000000] GICv3: no VLPI support, no direct LPI support
[    0.000000] GICv3: CPU0: found redistributor 0 region 0:0x0000000010200000
[    0.000000] ACPI: SRAT not present
[    0.000000] ITS [mem 0x10080000-0x1009ffff]
[    0.000000] ITS@0x0000000010080000: allocated 8192 Devices @4b4d50000 (indirect, esz 8, psz 64K, shr 1)
[    0.000000] ITS@0x0000000010080000: allocated 8192 Interrupt Collections @4b4d60000 (flat, esz 8, psz 64K, shr 1)
[    0.000000] GICv3: using LPI property table @0x00000004b4d70000
[    0.000000] ITS: Using hypervisor restricted LPI range [128]
[    0.000000] GICv3: CPU0: using allocated LPI pending table @0x00000004b4d80000
[    0.000000] rcu: 	Offload RCU callbacks from CPUs: (none).
[    0.000000] arch_timer: Enabling local workaround for ARM erratum 1418040
[    0.000000] arch_timer: cp15 timer(s) running at 121.87MHz (virt).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x383759f8ff, max_idle_ns: 881590415659 ns
[    0.000001] sched_clock: 56 bits at 121MHz, resolution 8ns, wraps every 4398046511103ns
[    0.000034] Console: colour dummy device 80x25
[    0.000148] printk: console [tty0] enabled
[    0.000164] ACPI: Core revision 20190816
[    0.000206] Calibrating delay loop (skipped), value calculated using timer frequency.. 243.75 BogoMIPS (lpj=1218750)
[    0.000211] pid_max: default: 32768 minimum: 301
[    0.000227] LSM: Security Framework initializing
[    0.000233] Yama: becoming mindful.
[    0.000238] SELinux:  Initializing.
[    0.000247] *** VALIDATE SELinux ***
[    0.000276] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    0.000281] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    0.000293] *** VALIDATE tmpfs ***
[    0.000405] *** VALIDATE proc ***
[    0.000450] *** VALIDATE cgroup1 ***
[    0.000452] *** VALIDATE cgroup2 ***
[    0.000607] ASID allocator initialised with 32768 entries
[    0.000622] rcu: Hierarchical SRCU implementation.
[    0.000871] Platform MSI: ITS@0x10080000 domain created
[    0.000876] PCI/MSI: ITS@0x10080000 domain created
[    0.000880] Remapping and enabling EFI services.
[    0.001014] smp: Bringing up secondary CPUs ...
[    0.001160] Detected PIPT I-cache on CPU1
[    0.001174] GICv3: CPU1: found redistributor 1 region 0:0x0000000010220000
[    0.001218] GICv3: CPU1: using allocated LPI pending table @0x00000004b4d90000
[    0.001235] arch_timer: Enabling local workaround for ARM erratum 1418040
[    0.001245] CPU1: Booted secondary processor 0x0000000001 [0x413fd0c1]
[    0.001286] smp: Brought up 1 node, 2 CPUs
[    0.001295] SMP: Total of 2 processors activated.
[    0.001297] CPU features: detected: Privileged Access Never
[    0.001299] CPU features: detected: LSE atomic instructions
[    0.001301] CPU features: detected: User Access Override
[    0.001303] CPU features: detected: 32-bit EL0 Support
[    0.001304] CPU features: detected: Common not Private translations
[    0.001306] CPU features: detected: RAS Extension Support
[    0.001308] CPU features: detected: Data cache clean to the PoU not required for I/D coherence
[    0.001310] CPU features: detected: Instruction cache invalidation not required for I/D coherence
[    0.001313] CPU features: detected: CRC32 instructions
[    0.025158] CPU: All CPU(s) started at EL1
[    0.025172] alternatives: patching kernel code
[    0.025780] devtmpfs: initialized
[    0.026020] Registered cp15_barrier emulation handler
[    0.026030] Registered setend emulation handler
[    0.026078] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.026084] futex hash table entries: 512 (order: 3, 32768 bytes, linear)
[    0.026414] pinctrl core: initialized pinctrl subsystem
[    0.026523] SMBIOS 3.0.0 present.
[    0.026527] DMI: Amazon EC2 c6gd.large/, BIOS 1.0 11/1/2018
[    0.026641] NET: Registered protocol family 16
[    0.026863] DMA: preallocated 256 KiB pool for atomic allocations
[    0.026866] audit: initializing netlink subsys (disabled)
[    0.026910] audit: type=2000 audit(0.020:1): state=initialized audit_enabled=0 res=1
[    0.027027] cpuidle: using governor menu
[    0.027069] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
[    0.027098] ACPI: bus type PCI registered
[    0.027100] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
[    0.027111] Serial: AMBA PL011 UART driver
[    0.028255] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages
[    0.028259] HugeTLB registered 32.0 MiB page size, pre-allocated 0 pages
[    0.028261] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[    0.028263] HugeTLB registered 64.0 KiB page size, pre-allocated 0 pages
[    0.062889] cryptd: max_cpu_qlen set to 1000
[    0.069660] ACPI: Added _OSI(Module Device)
[    0.069665] ACPI: Added _OSI(Processor Device)
[    0.069667] ACPI: Added _OSI(3.0 _SCP Extensions)
[    0.069669] ACPI: Added _OSI(Processor Aggregator Device)
[    0.069672] ACPI: Added _OSI(Linux-Dell-Video)
[    0.069674] ACPI: Added _OSI(Linux-Lenovo-NV-HDMI-Audio)
[    0.069676] ACPI: Added _OSI(Linux-HPI-Hybrid-Graphics)
[    0.070288] ACPI: 1 ACPI AML tables successfully acquired and loaded
[    0.070467] ACPI: Interpreter enabled
[    0.070469] ACPI: Using GIC for interrupt routing
[    0.070478] ACPI: MCFG table detected, 1 entries
[    0.072189] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-0f])
[    0.072198] acpi PNP0A08:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3]
[    0.072268] acpi PNP0A08:00: _OSC: platform does not support [SHPCHotplug LTR]
[    0.072324] acpi PNP0A08:00: _OSC: OS now controls [PCIeHotplug PME AER PCIeCapability]
[    0.072408] acpi PNP0A08:00: ECAM area [mem 0x20000000-0x20ffffff] reserved by PNP0C02:00
[    0.072416] acpi PNP0A08:00: ECAM at [mem 0x20000000-0x20ffffff] for [bus 00-0f]
[    0.072432] Remapped I/O 0x000000001fff0000 to [io  0x0000-0xffff window]
[    0.072650] acpiphp: Slot [1] registered
[    0.072663] acpiphp: Slot [2] registered
[    0.072674] acpiphp: Slot [3] registered
[    0.072686] acpiphp: Slot [4] registered
[    0.072698] acpiphp: Slot [5] registered
[    0.072709] acpiphp: Slot [6] registered
[    0.072720] acpiphp: Slot [7] registered
[    0.072731] acpiphp: Slot [8] registered
[    0.072742] acpiphp: Slot [9] registered
[    0.072754] acpiphp: Slot [10] registered
[    0.072766] acpiphp: Slot [11] registered
[    0.072778] acpiphp: Slot [12] registered
[    0.072789] acpiphp: Slot [13] registered
[    0.072800] acpiphp: Slot [14] registered
[    0.072811] acpiphp: Slot [15] registered
[    0.072822] acpiphp: Slot [16] registered
[    0.072834] acpiphp: Slot [17] registered
[    0.072845] acpiphp: Slot [18] registered
[    0.072855] acpiphp: Slot [19] registered
[    0.072866] acpiphp: Slot [20] registered
[    0.072877] acpiphp: Slot [21] registered
[    0.072890] acpiphp: Slot [22] registered
[    0.072901] acpiphp: Slot [23] registered
[    0.072912] acpiphp: Slot [24] registered
[    0.072923] acpiphp: Slot [25] registered
[    0.072933] acpiphp: Slot [26] registered
[    0.072944] acpiphp: Slot [27] registered
[    0.072956] acpiphp: Slot [28] registered
[    0.072967] acpiphp: Slot [29] registered
[    0.072977] acpiphp: Slot [30] registered
[    0.072988] acpiphp: Slot [31] registered
[    0.073007] PCI host bridge to bus 0000:00
[    0.073010] pci_bus 0000:00: root bus resource [mem 0x80000000-0xffffffff window]
[    0.073012] pci_bus 0000:00: root bus resource [io  0x0000-0xffff window]
[    0.073015] pci_bus 0000:00: root bus resource [mem 0x400000000000-0x407fffffffff window]
[    0.073017] pci_bus 0000:00: root bus resource [bus 00-0f]
[    0.073048] pci 0000:00:00.0: [1d0f:0200] type 00 class 0x060000
[    0.073315] pci 0000:00:01.0: [1d0f:8250] type 00 class 0x070003
[    0.073370] pci 0000:00:01.0: reg 0x10: [mem 0x8011e000-0x8011efff]
[    0.073597] pci 0000:00:04.0: [1d0f:8061] type 00 class 0x010802
[    0.074781] pci 0000:00:04.0: reg 0x10: [mem 0x80118000-0x8011bfff]
[    0.078896] pci 0000:00:04.0: PME# supported from D0 D1 D2 D3hot D3cold
[    0.079100] pci 0000:00:05.0: [1d0f:ec20] type 00 class 0x020000
[    0.079150] pci 0000:00:05.0: reg 0x10: [mem 0x80114000-0x80117fff]
[    0.079178] pci 0000:00:05.0: reg 0x18: [mem 0x80000000-0x800fffff pref]
[    0.079205] pci 0000:00:05.0: reg 0x20: [mem 0x80100000-0x8010ffff]
[    0.079387] pci 0000:00:05.0: PME# supported from D0 D1 D2 D3hot D3cold
[    0.079601] pci 0000:00:1f.0: [1d0f:cd01] type 00 class 0x010802
[    0.079891] pci 0000:00:1f.0: reg 0x10: [mem 0x80110000-0x80113fff]
[    0.080366] pci 0000:00:1f.0: reg 0x18: [mem 0x8011c000-0x8011dfff pref]
[    0.081463] pci 0000:00:1f.0: PME# supported from D0 D1 D2 D3hot D3cold
[    0.081612] pci 0000:00:05.0: BAR 2: assigned [mem 0x80000000-0x800fffff pref]
[    0.081622] pci 0000:00:05.0: BAR 4: assigned [mem 0x80100000-0x8010ffff]
[    0.081630] pci 0000:00:04.0: BAR 0: assigned [mem 0x80110000-0x80113fff]
[    0.082253] pci 0000:00:05.0: BAR 0: assigned [mem 0x80114000-0x80117fff]
[    0.082262] pci 0000:00:1f.0: BAR 0: assigned [mem 0x80118000-0x8011bfff]
[    0.082393] pci 0000:00:1f.0: BAR 2: assigned [mem 0x8011c000-0x8011dfff pref]
[    0.082401] pci 0000:00:01.0: BAR 0: assigned [mem 0x8011e000-0x8011efff]
[    0.082412] pci_bus 0000:00: resource 4 [mem 0x80000000-0xffffffff window]
[    0.082414] pci_bus 0000:00: resource 5 [io  0x0000-0xffff window]
[    0.082416] pci_bus 0000:00: resource 6 [mem 0x400000000000-0x407fffffffff window]
[    0.082448] ACPI: PCI Interrupt Link [GSI0] (IRQs *35)
[    0.082455] ACPI: PCI Interrupt Link [GSI1] (IRQs *36)
[    0.082462] ACPI: PCI Interrupt Link [GSI2] (IRQs *37)
[    0.082468] ACPI: PCI Interrupt Link [GSI3] (IRQs *38)
[    0.082785] iommu: Default domain type: Translated 
[    0.082832] vgaarb: loaded
[    0.082913] SCSI subsystem initialized
[    0.082978] ACPI: bus type USB registered
[    0.082997] usbcore: registered new interface driver usbfs
[    0.083004] usbcore: registered new interface driver hub
[    0.083010] usbcore: registered new device driver usb
[    0.083081] EDAC MC: Ver: 3.0.0
[    0.083197] Registered efivars operations
[    0.083357] NetLabel: Initializing
[    0.083360] NetLabel:  domain hash size = 128
[    0.083362] NetLabel:  protocols = UNLABELED CIPSOv4 CALIPSO
[    0.083374] NetLabel:  unlabeled traffic allowed by default
[    0.083460] clocksource: Switched to clocksource arch_sys_counter
[    0.103746] *** VALIDATE bpf ***
[    0.103805] VFS: Disk quotas dquot_6.6.0
[    0.103818] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.103840] *** VALIDATE ramfs ***
[    0.103842] *** VALIDATE hugetlbfs ***
[    0.103889] pnp: PnP ACPI init
[    0.103984] system 00:00: [mem 0x20000000-0x2fffffff] could not be reserved
[    0.103994] pnp: PnP ACPI: found 1 devices
[    0.105371] thermal_sys: Registered thermal governor 'fair_share'
[    0.105371] thermal_sys: Registered thermal governor 'step_wise'
[    0.105374] thermal_sys: Registered thermal governor 'user_space'
[    0.105408] NET: Registered protocol family 2
[    0.105439] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)
[    0.105913] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)
[    0.105933] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)
[    0.106017] TCP bind hash table entries: 32768 (order: 7, 524288 bytes, linear)
[    0.106188] TCP: Hash tables configured (established 32768 bind 32768)
[    0.106204] UDP hash table entries: 2048 (order: 4, 65536 bytes, linear)
[    0.106235] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear)
[    0.106286] NET: Registered protocol family 1
[    0.106291] NET: Registered protocol family 44
[    0.106351] PCI: CLS 0 bytes, default 64
[    0.106386] Trying to unpack rootfs image as initramfs...
[    0.125923] Freeing initrd memory: 9440K
[    0.126088] hw perfevents: enabled with armv8_pmuv3_0 PMU driver, 4 counters available
[    0.126092] kvm [1]: HYP mode not available
[    0.142535] Initialise system trusted keyrings
[    0.142570] workingset: timestamp_bits=44 max_order=20 bucket_order=0
[    0.143494] zbud: loaded
[    0.143642] SGI XFS with ACLs, security attributes, no debug enabled
[    0.144011] NET: Registered protocol family 38
[    0.144017] Key type asymmetric registered
[    0.144019] Asymmetric key parser 'x509' registered
[    0.144027] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)
[    0.144063] io scheduler mq-deadline registered
[    0.144065] io scheduler kyber registered
[    0.144085] io scheduler bfq registered
[    0.144710] pl061_gpio ARMH0061:00: PL061 GPIO chip registered
[    0.144760] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4
[    0.146269] input: Power Button as /devices/LNXSYSTM:00/LNXSYBUS:00/PNP0C0C:00/input/input0
[    0.146290] ACPI: Power Button [PWRB]
[    0.146419] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[    0.146700] PCI Interrupt Link [GSI2] enabled at IRQ 37
[    0.146732] serial 0000:00:01.0: enabling device (0010 -> 0012)
[    0.146887] printk: console [ttyS0] disabled
[    0.172567] 0000:00:01.0: ttyS0 at MMIO 0x8011e000 (irq = 6, base_baud = 115200) is a 16550A
[    0.421939] printk: console [ttyS0] enabled
[    0.422889] rdac: device handler registered
[    0.423593] hp_sw: device handler registered
[    0.424264] emc: device handler registered
[    0.424913] alua: device handler registered
[    0.425854] PCI Interrupt Link [GSI0] enabled at IRQ 35
[    0.426718] nvme nvme0: pci function 0000:00:04.0
[    0.427522] PCI Interrupt Link [GSI3] enabled at IRQ 38
[    0.428378] nvme nvme1: pci function 0000:00:1f.0
[    0.429206] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    0.430289] ehci-pci: EHCI PCI platform driver
[    0.430967] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    0.431904] ohci-pci: OHCI PCI platform driver
[    0.432572] uhci_hcd: USB Universal Host Controller Interface driver
[    0.433601] usbcore: registered new interface driver usbserial_generic
[    0.434582] usbserial: USB Serial support registered for generic
[    0.435527] mousedev: PS/2 mouse device common for all mice
[    0.436522] rtc-efi rtc-efi: registered as rtc0
[    0.437217] i2c /dev entries driver
[    0.437754] IR NEC protocol handler initialized
[    0.438459] IR RC5(x/sz) protocol handler initialized
[    0.439223] IR RC6 protocol handler initialized
[    0.439914] IR JVC protocol handler initialized
[    0.440599] IR Sony protocol handler initialized
[    0.441325] IR SANYO protocol handler initialized
[    0.442027] IR Sharp protocol handler initialized
[    0.442738] IR MCE Keyboard/mouse protocol handler initialized
[    0.443631] IR XMP protocol handler initialized
[    0.444383] EFI Variables Facility v0.08 2004-May-17
[    0.446422] hidraw: raw HID events driver (C) Jiri Kosina
[    0.447283] usbcore: registered new interface driver usbhid
[    0.448092] usbhid: USB HID core driver
[    0.448709] drop_monitor: Initializing network drop monitor service
[    0.449713] Initializing XFRM netlink socket
[    0.450456] NET: Registered protocol family 10
[    0.451315] Segment Routing with IPv6
[    0.451910] NET: Registered protocol family 17
[    0.452738] registered taskstats version 1
[    0.453379] Loading compiled-in X.509 certificates
[    0.455521] alg: No test for pkcs1pad(rsa,sha1) (pkcs1pad(rsa-generic,sha1))
[    0.457308] Loaded X.509 cert 'Build time autogenerated kernel key: fccc455f7ccdaede87bba1b9018e85d3dd892f88'
[    0.458821] zswap: loaded using pool lzo/zbud
[    0.461114] Key type big_key registered
[    0.461967] rtc-efi rtc-efi: setting system clock to 2022-12-22T11:27:16 UTC (1671708436)
[    0.665307] nvme nvme0: 2/0/0 default/read/poll queues
[    0.666521] nvme nvme1: 2/0/0 default/read/poll queues
[    0.671011] GPT:Primary header thinks Alt. header is not at the end of the disk.
[    0.672134] GPT:8388607 != 20971519
[    0.672677] GPT:Alternate GPT header not at the end of the disk.
[    0.673610] GPT:8388607 != 20971519
[    0.674160] GPT: Use GNU Parted to correct GPT errors.
[    0.674954]  nvme0n1: p1 p128
[    0.714176] Freeing unused kernel memory: 1408K
[    0.714983] Run /init as init process
[    0.753862] systemd[1]: systemd 219 running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 -SECCOMP +BLKID +ELFUTILS +KMOD +IDN)
[    0.756616] systemd[1]: Detected virtualization amazon.
[    0.757410] systemd[1]: Detected architecture arm64.
[    0.758151] systemd[1]: Running in initial RAM disk.

Welcome to �[0;34mAmazon Linux 2 dracut-033-535.amzn2.1.6 (Initramfs)�[0m!

[    0.760804] systemd[1]: No hostname configured.
[    0.761517] systemd[1]: Set hostname to <localhost>.
[    0.762294] systemd[1]: Initializing machine ID from VM UUID.
[    0.785736] systemd[1]: Reached target Timers.
[�[32m  OK  �[0m] Reached target Timers.
[    0.787781] systemd[1]: Created slice Root Slice.
[�[32m  OK  �[0m] Created slice Root Slice.
[    0.789599] systemd[1]: Listening on udev Control Socket.
[�[32m  OK  �[0m] Listening on udev Control Socket.
[�[32m  OK  �[0m] Created slice System Slice.
[�[32m  OK  �[0m] Listening on Journal Socket.
[�[32m  OK  �[0m] Reached target Slices.
[�[32m  OK  �[0m] Reached target Swap.
         Starting Create list of required st... nodes for the current kernel...
[�[32m  OK  �[0m] Started Dispatch Password Requests to Console Directory Watch.
[�[32m  OK  �[0m] Reached target Paths.
         Starting Journal Service...
[�[32m  OK  �[0m] Reached target Local File Systems.
[�[32m  OK  �[0m] Listening on udev Kernel Socket.
[�[32m  OK  �[0m] Reached target Sockets.
         Starting Apply Kernel Variables...
[�[32m  OK  �[0m] Started Journal Service.
[�[32m  OK  �[0m] Started Create list of required sta...ce nodes for the current kernel.
[�[32m  OK  �[0m] Started Apply Kernel Variables.
         Starting Create Static Device Nodes in /dev...
[�[32m  OK  �[0m] Started Create Static Device Nodes in /dev.
         Starting udev Kernel Device Manager...
[�[32m  OK  �[0m] Started udev Kernel Device Manager.
         Starting udev Coldplug all Devices...
         Mounting Configuration File System...
[�[32m  OK  �[0m] Mounted Configuration File System.
[�[32m  OK  �[0m] Started udev Coldplug all Devices.
         Starting dracut initqueue hook...
[�[32m  OK  �[0m] Reached target System Initialization.
[�[32m  OK  �[0m] Reached target Basic System.
[�[32m  OK  �[0m] Found device Amazon Elastic Block Store /.
         Starting File System Check on /dev/...c-62db-4f3c-98c9-cac9f4c74f58...
[�[32m  OK  �[0m] Started File System Check on /dev/d...eec-62db-4f3c-98c9-cac9f4c74f58.
[�[32m  OK  �[0m] Started dracut initqueue hook.
[�[32m  OK  �[0m] Reached target Remote File Systems (Pre).
[�[32m  OK  �[0m] Reached target Remote File Systems.
         Mounting /sysroot...
[    1.174778] XFS (nvme0n1p1): Mounting V5 Filesystem
[    2.254001] XFS (nvme0n1p1): Ending clean mount
[�[32m  OK  �[0m] Mounted /sysroot.
[�[32m  OK  �[0m] Reached target Initrd Root File System.
         Starting Reload Configuration from the Real Root...
[�[32m  OK  �[0m] Started Reload Configuration from the Real Root.
[�[32m  OK  �[0m] Reached target Initrd File Systems.
[�[32m  OK  �[0m] Reached target Initrd Default Target.
         Starting dracut pre-pivot and cleanup hook...
[�[32m  OK  �[0m] Started dracut pre-pivot and cleanup hook.
         Starting Cleaning Up and Shutting Down Daemons...
[�[32m  OK  �[0m] Stopped target Timers.
[�[32m  OK  �[0m] Stopped dracut pre-pivot and cleanup hook.
[�[32m  OK  �[0m] Stopped target Initrd Default Target.
[�[32m  OK  �[0m] Stopped target Basic System.
[�[32m  OK  �[0m] Stopped target Paths.
[�[32m  OK  �[0m] Stopped target Slices.
[�[32m  OK  �[0m] Stopped target System Initialization.
         Stopping udev Kernel Device Manager...
[�[32m  OK  �[0m] Stopped target Local File Systems.
[�[32m  OK  �[0m] Stopped Apply Kernel Variables.
[�[32m  OK  �[0m] Stopped target Sockets.
[�[32m  OK  �[0m] Stopped target Remote File Systems.
[�[32m  OK  �[0m] Stopped target Remote File Systems (Pre).
[�[32m  OK  �[0m] Stopped dracut initqueue hook.
[�[32m  OK  �[0m] Stopped udev Coldplug all Devices.
[�[32m  OK  �[0m] Stopped target Swap.
[�[32m  OK  �[0m] Stopped Dispatch Password Requests to Console Directory Watch.
[�[32m  OK  �[0m] Stopped udev Kernel Device Manager.
[�[32m  OK  �[0m] Stopped Create Static Device Nodes in /dev.
[�[32m  OK  �[0m] Stopped Create list of required sta...ce nodes for the current kernel.
[�[32m  OK  �[0m] Closed udev Control Socket.
[�[32m  OK  �[0m] Closed udev Kernel Socket.
         Starting Cleanup udevd DB...
[�[32m  OK  �[0m] Started Cleaning Up and Shutting Down Daemons.
[�[32m  OK  �[0m] Started Cleanup udevd DB.
[�[32m  OK  �[0m] Reached target Switch Root.
         Starting Switch Root...
[    2.805136] systemd-journald[255]: Received SIGTERM from PID 1 (systemd).
[    3.258099] printk: systemd: 13 output lines suppressed due to ratelimiting
[    4.930360] SELinux:  Disabled at runtime.
[    5.093480] audit: type=1404 audit(1671708441.129:2): enforcing=0 old_enforcing=0 auid=4294967295 ses=4294967295 enabled=0 old-enabled=1 lsm=selinux res=1

Welcome to �[0;33mAmazon Linux 2�[0m!

[�[32m  OK  �[0m] Stopped Switch Root.
[�[32m  OK  �[0m] Stopped Journal Service.
         Starting Journal Service...
[�[32m  OK  �[0m] Listening on LVM2 poll daemon socket.
[�[32m  OK  �[0m] Created slice system-serial\x2dgetty.slice.
         Starting Read and set NIS domainname from /etc/sysconfig/network...
         Starting Create list of required st... nodes for the current kernel...
         Mounting Debug File System...
[�[32m  OK  �[0m] Reached target Local Encrypted Volumes.
[�[32m  OK  �[0m] Listening on udev Kernel Socket.
         Mounting POSIX Message Queue File System...
[�[32m  OK  �[0m] Listening on LVM2 metadata daemon socket.
         Mounting Huge Pages File System...
[�[32m  OK  �[0m] Listening on /dev/initctl Compatibility Named Pipe.
[�[32m  OK  �[0m] Created slice system-getty.slice.
[�[32m  OK  �[0m] Listening on Device-mapper event daemon FIFOs.
[�[32m  OK  �[0m] Started Forward Password Requests to Wall Directory Watch.
[�[32m  OK  �[0m] Started Dispatch Password Requests to Console Directory Watch.
         Starting Remount Root and Kernel File Systems...
[�[32m  OK  �[0m] Created slice User and Session Slice.
[�[32m  OK  �[0m] Listening on udev Control Socket.
         Starting Monitoring of LVM2 mirrors... dmeventd or progress polling...
[�[32m  OK  �[0m] Stopped target Switch Root.
         Starting Setup Virtual Console...
[�[32m  OK  �[0m] Stopped target Initrd File Systems.
[�[32m  OK  �[0m] Reached target Slices.
[�[32m  OK  �[0m] Reached target Swap.
[�[32m  OK  �[0m] Listening on Delayed Shutdown Socket.
[�[32m  OK  �[0m] Created slice system-selinux\x2dpol...grate\x2dlocal\x2dchanges.slice.
[�[32m  OK  �[0m] Set up automount Arbitrary Executab...ats File System Automount Point.
[�[32m  OK  �[0m] Stopped target Initrd Root File System.
[�[32m  OK  �[0m] Started Create list of required sta...ce nodes for the current kernel.
         Starting Create Static Device Nodes in /dev...
[�[32m  OK  �[0m] Mounted Debug File System.
[�[32m  OK  �[0m] Mounted POSIX Message Queue File System.
[�[32m  OK  �[0m] Mounted Huge Pages File System.
[�[32m  OK  �[0m] Started Setup Virtual Console.
[�[32m  OK  �[0m] Started Journal Service.
[�[32m  OK  �[0m] Started Read and set NIS domainname from /etc/sysconfig/network.
[�[32m  OK  �[0m] Started LVM2 metadata daemon.
[    8.474969] xfs filesystem being remounted at / supports timestamps until 2038 (0x7fffffff)
[�[32m  OK  �[0m] Started Remount Root and Kernel File Systems.
         Starting udev Coldplug all Devices...
         Starting Flush Journal to Persistent Storage...
         Starting Configure read-only root support...
         Starting Relabel kernel modules early in the boot, if needed...
[�[32m  OK  �[0m] Started Relabel kernel modules early in the boot, if needed.
         Starting Load Kernel Modules...
[�[32m  OK  �[0m] Started udev Coldplug all Devices.
[    8.671140] systemd-journald[370]: Received request to flush runtime journal from PID 1
[�[32m  OK  �[0m] Started Flush Journal to Persistent Storage.
[�[32m  OK  �[0m] Started Configure read-only root support.
         Starting Load/Save Random Seed...
[�[32m  OK  �[0m] Started Load/Save Random Seed.
[�[32m  OK  �[0m] Started Create Static Device Nodes in /dev.
         Starting udev Kernel Device Manager...
[    9.231127] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
[    9.236806] Bridge firewalling registered
[    9.475528] PCI Interrupt Link [GSI1] enabled at IRQ 36
[    9.476360] ena 0000:00:05.0: Elastic Network Adapter (ENA) v2.8.0g
[    9.477349] ena 0000:00:05.0: enabling device (0010 -> 0012)
[�[32m  OK  �[0m] Started udev Kernel Device Manager.
[    9.489106] ena 0000:00:05.0: ENA device version: 0.10
[    9.489912] ena 0000:00:05.0: ENA controller version: 0.0.1 implementation version 1
[    9.592094] ena 0000:00:05.0: Elastic Network Adapter (ENA) found at mem 80114000, mac addr 02:f4:87:4f:09:79
[�[32m  OK  �[0m] Started Load Kernel Modules.
         Starting Apply Kernel Variables...
[�[32m  OK  �[0m] Found device /dev/ttyS0.
[�[32m  OK  �[0m] Started Apply Kernel Variables.
[�[32m  OK  �[0m] Found device Amazon Elastic Block Store EFI\x20System\x20Partition.
[�[32m  OK  �[0m] Started Monitoring of LVM2 mirrors,...ng dmeventd or progress polling.
[�[32m  OK  �[0m] Reached target Local File Systems (Pre).
         Mounting /boot/efi...
[�[32m  OK  �[0m] Mounted /boot/efi.
[�[32m  OK  �[0m] Reached target Local File Systems.
         Starting Commit a transient machine-id on disk...
         Starting Create Volatile Files and Directories...
         Starting Preprocess NFS configuration...
[�[32m  OK  �[0m] Started Commit a transient machine-id on disk.
[�[32m  OK  �[0m] Started Create Volatile Files and Directories.
         Starting Security Auditing Service...
         Mounting RPC Pipe File System...
[�[32m  OK  �[0m] Started Preprocess NFS configuration.
[   12.109715] RPC: Registered named UNIX socket transport module.
[   12.110634] RPC: Registered udp transport module.
[   12.111355] RPC: Registered tcp transport module.
[   12.112074] RPC: Registered tcp NFSv4.1 backchannel transport module.
[�[32m  OK  �[0m] Mounted RPC Pipe File System.
[�[32m  OK  �[0m] Reached target rpc_pipefs.target.
[�[32m  OK  �[0m] Started Security Auditing Service.
         Starting Update UTMP about System Boot/Shutdown...
[�[32m  OK  �[0m] Started Update UTMP about System Boot/Shutdown.
[�[32m  OK  �[0m] Reached target System Initialization.
[�[32m  OK  �[0m] Listening on RPCbind Server Activation Socket.
         Starting RPC bind service...
[�[32m  OK  �[0m] Listening on D-Bus System Message Bus Socket.
[�[32m  OK  �[0m] Reached target Sockets.
[�[32m  OK  �[0m] Started Flexible branding.
[�[32m  OK  �[0m] Reached target Paths.
[�[32m  OK  �[0m] Reached target Basic System.
         Starting NTP client/server...
         Starting Hardware RNG Entropy Gatherer Wake threshold service...
[�[32m  OK  �[0m] Started D-Bus System Message Bus.
[   12.715854] xfs filesystem being remounted at /tmp supports timestamps until 2038 (0x7fffffff)
[   12.717901] xfs filesystem being remounted at /var/tmp supports timestamps until 2038 (0x7fffffff)
[�[32m  OK  �[0m] Started irqbalance daemon.
         Starting GSSAPI Proxy Daemon...
         Starting Initial cloud-init job (pre-networking)...
         Starting Login Service...
         Starting Dump dmesg to /var/log/dmesg...
[�[32m  OK  �[0m] Started Daily Cleanup of Temporary Directories.
[�[32m  OK  �[0m] Reached target Timers.
[�[32m  OK  �[0m] Started Hardware RNG Entropy Gatherer Wake threshold service.
[�[32m  OK  �[0m] Started Hardware RNG Entropy Gatherer Daemon.
[�[32m  OK  �[0m] Started Login Service.
[�[32m  OK  �[0m] Started RPC bind service.
[�[32m  OK  �[0m] Started NTP client/server.
[�[32m  OK  �[0m] Started Dump dmesg to /var/log/dmesg.
[�[32m  OK  �[0m] Started GSSAPI Proxy Daemon.
[�[32m  OK  �[0m] Reached target NFS client services.
[�[32m  OK  �[0m] Reached target Remote File Systems (Pre).
[�[32m  OK  �[0m] Reached target Remote File Systems.
[   17.112396] cloud-init[514]: Cloud-init v. 19.3-46.amzn2 running 'init-local' at Thu, 22 Dec 2022 11:27:33 +0000. Up 17.02 seconds.
[�[32m  OK  �[0m] Started Initial cloud-init job (pre-networking).
[�[32m  OK  �[0m] Reached target Network (Pre).
         Starting LSB: Bring up/down networking...
[   19.055648] ena 0000:00:05.0 eth0: Local page cache is disabled for less than 16 channels
[�[32m  OK  �[0m] Started LSB: Bring up/down networking.
         Starting Initial cloud-init job (metadata service crawler)...
[�[32m  OK  �[0m] Reached target Network.
         Starting Postfix Mail Transport Agent...
[   19.554358] cloud-init[819]: Cloud-init v. 19.3-46.amzn2 running 'init' at Thu, 22 Dec 2022 11:27:35 +0000. Up 19.52 seconds.
[   19.567713] cloud-init[819]: ci-info: +++++++++++++++++++++++++++++++++++++Net device info++++++++++++++++++++++++++++++++++++++
[   19.571432] cloud-init[819]: ci-info: +--------+------+---------------------------+---------------+--------+-------------------+
[   19.575854] cloud-init[819]: ci-info: | Device |  Up  |          Address          |      Mask     | Scope  |     Hw-Address    |
[   19.578982] cloud-init[819]: ci-info: +--------+------+---------------------------+---------------+--------+-------------------+
[   19.582095] cloud-init[819]: ci-info: |  eth0  | True |        10.2.23.188        | 255.255.254.0 | global | 02:f4:87:4f:09:79 |
[   19.585223] cloud-init[819]: ci-info: |  eth0  | True | fe80::f4:87ff:fe4f:979/64 |       .       |  link  | 02:f4:87:4f:09:79 |
[   19.588302] cloud-init[819]: ci-info: |   lo   | True |         127.0.0.1         |   255.0.0.0   |  host  |         .         |
[   19.591427] cloud-init[819]: ci-info: |   lo   | True |          ::1/128          |       .       |  host  |         .         |
[   19.594507] cloud-init[819]: ci-info: +--------+------+---------------------------+---------------+--------+-------------------+
[   19.597574] cloud-init[819]: ci-info: +++++++++++++++++++++++++++++++Route IPv4 info+++++++++++++++++++++++++++++++
[   19.600778] cloud-init[819]: ci-info: +-------+-----------------+-----------+-----------------+-----------+-------+
[   19.603721] cloud-init[819]: ci-info: | Route |   Destination   |  Gateway  |     Genmask     | Interface | Flags |
[   19.606541] cloud-init[819]: ci-info: +-------+-----------------+-----------+-----------------+-----------+-------+
[   19.609303] cloud-init[819]: ci-info: |   0   |     0.0.0.0     | 10.2.22.1 |     0.0.0.0     |    eth0   |   UG  |
[   19.612090] cloud-init[819]: ci-info: |   1   |    10.2.22.0    |  0.0.0.0  |  255.255.254.0  |    eth0   |   U   |
[   19.614857] cloud-init[819]: ci-info: |   2   | 169.254.169.254 |  0.0.0.0  | 255.255.255.255 |    eth0   |   UH  |
[   19.617641] cloud-init[819]: ci-info: +-------+-----------------+-----------+-----------------+-----------+-------+
[   19.620393] cloud-init[819]: ci-info: +++++++++++++++++++Route IPv6 info+++++++++++++++++++
[   19.622645] cloud-init[819]: ci-info: +-------+-------------+---------+-----------+-------+
[   19.624871] cloud-init[819]: ci-info: | Route | Destination | Gateway | Interface | Flags |
[   19.627480] cloud-init[819]: ci-info: +-------+-------------+---------+-----------+-------+
[   19.629813] cloud-init[819]: ci-info: |   9   |  fe80::/64  |    ::   |    eth0   |   U   |
[   19.632147] cloud-init[819]: ci-info: |   11  |    local    |    ::   |    eth0   |   U   |
[   19.634807] cloud-init[819]: ci-info: |   12  |  multicast  |    ::   |    eth0   |   U   |
[   19.637068] cloud-init[819]: ci-info: +-------+-------------+---------+-----------+-------+
         Starting Hostname Service...
[   19.974955] xfs filesystem being remounted at /tmp supports timestamps until 2038 (0x7fffffff)
[   19.976689] xfs filesystem being remounted at /var/tmp supports timestamps until 2038 (0x7fffffff)
[�[32m  OK  �[0m] Started Hostname Service.
[�[32m  OK  �[0m] Started Postfix Mail Transport Agent.
[�[32m  OK  �[0m] Started Initial cloud-init job (metadata service crawler).
[�[32m  OK  �[0m] Reached target Network is Online.
[�[32m  OK  �[0m] Started amazon-ssm-agent.
         Starting System Logging Service...
         Starting Dynamically Generate Message Of The Day...
         Starting Notify NFS peers of a restart...
         Starting OpenSSH Server Key Generation...
[�[32m  OK  �[0m] Reached target Cloud-config availability.
         Starting Apply the settings specified in cloud-config...
         Starting Permit User Sessions...
[�[32m  OK  �[0m] Started Notify NFS peers of a restart.
[�[32m  OK  �[0m] Started Permit User Sessions.
[�[32m  OK  �[0m] Started Serial Getty on ttyS0.
[�[32m  OK  �[0m] Started Getty on tty1.
[�[32m  OK  �[0m] Reached target Login Prompts.
[�[32m  OK  �[0m] Started Command Scheduler.
[�[32m  OK  �[0m] Started System Logging Service.
[�[32m  OK  �[0m] Started OpenSSH Server Key Generation.
         Starting OpenSSH server daemon...
[   21.362323] cloud-init[1017]: Cloud-init v. 19.3-46.amzn2 running 'modules:config' at Thu, 22 Dec 2022 11:27:37 +0000. Up 21.30 seconds.
[�[32m  OK  �[0m] Started OpenSSH server daemon.
[   22.120770] cloud-init[1017]: Loaded plugins: priorities, update-motd, versionlock
2022/12/22 11:27:39Z: Amazon SSM Agent v3.1.1732.0 is running
2022/12/22 11:27:39Z: OsProductName: Amazon Linux
2022/12/22 11:27:39Z: OsVersion: 2

Amazon Linux 2
Kernel 5.4.219-126.411.amzn2.aarch64 on an aarch64

ip-10-2-23-188 login: [   27.421605] cloud-init[1017]: --> pcre2-10.23-2.amzn2.0.2.aarch64 from installed removed (updateinfo)
[   27.423099] cloud-init[1017]: --> aws-cfn-bootstrap-2.0-20.amzn2.noarch from amzn2-core removed (updateinfo)
[   27.424493] cloud-init[1017]: --> tzdata-2022e-1.amzn2.0.1.noarch from @amzn2-core removed (updateinfo)
[   27.424596] cloud-init[1017]: --> 12:dhclient-4.2.5-79.amzn2.1.2.aarch64 from amzn2-core removed (updateinfo)
[   27.424683] cloud-init[1017]: --> nspr-4.34.0-3.1.amzn2.aarch64 from amzn2-core removed (updateinfo)
[   27.424763] cloud-init[1017]: --> 12:dhcp-libs-4.2.5-79.amzn2.1.1.aarch64 from installed removed (updateinfo)
[   27.424840] cloud-init[1017]: --> glibc-all-langpacks-2.26-61.amzn2.aarch64 from @amzn2-core removed (updateinfo)
[   27.424925] cloud-init[1017]: --> glibc-minimal-langpack-2.26-61.amzn2.aarch64 from @amzn2-core removed (updateinfo)
[   27.425007] cloud-init[1017]: --> 1:python2-dateutil-2.6.1-3.amzn2.noarch from amzn2-core removed (updateinfo)
[   27.425089] cloud-init[1017]: --> pcre2-10.23-11.amzn2.0.1.aarch64 from amzn2-core removed (updateinfo)
[   27.425173] cloud-init[1017]: --> aws-cfn-bootstrap-2.0-10.amzn2.noarch from @amzn2-core removed (updateinfo)
[   27.425255] cloud-init[1017]: --> python2-jsonschema-2.5.1-3.amzn2.0.2.noarch from amzn2-core removed (updateinfo)
[   27.425337] cloud-init[1017]: --> nss-util-3.79.0-1.amzn2.aarch64 from amzn2-core removed (updateinfo)
[   27.425416] cloud-init[1017]: --> glibc-all-langpacks-2.26-62.amzn2.aarch64 from amzn2-core removed (updateinfo)
[   27.425500] cloud-init[1017]: --> python2-rsa-3.4.1-1.amzn2.0.3.noarch from amzn2-core removed (updateinfo)
[   27.425580] cloud-init[1017]: --> glibc-minimal-langpack-2.26-62.amzn2.aarch64 from amzn2-core removed (updateinfo)
[   27.425658] cloud-init[1017]: --> python2-colorama-0.3.9-3.amzn2.0.1.noarch from amzn2-core removed (updateinfo)
[   27.425736] cloud-init[1017]: --> python2-jmespath-0.9.3-1.amzn2.0.2.noarch from amzn2-core removed (updateinfo)
[   27.425816] cloud-init[1017]: --> nss-tools-3.79.0-4.amzn2.aarch64 from amzn2-core removed (updateinfo)
[   27.425900] cloud-init[1017]: --> glibc-2.26-62.amzn2.aarch64 from amzn2-core removed (updateinfo)
[   27.425981] cloud-init[1017]: --> e2fsprogs-libs-1.42.9-19.amzn2.aarch64 from installed removed (updateinfo)
[   27.426059] cloud-init[1017]: --> ncurses-libs-6.0-8.20170212.amzn2.1.3.aarch64 from installed removed (updateinfo)
[   27.426136] cloud-init[1017]: --> nss-sysinit-3.79.0-4.amzn2.aarch64 from amzn2-core removed (updateinfo)
[   27.426231] cloud-init[1017]: --> libcom_err-1.42.9-19.amzn2.aarch64 from installed removed (updateinfo)
[   27.426314] cloud-init[1017]: --> ncurses-base-6.0-8.20170212.amzn2.1.4.noarch from amzn2-core removed (updateinfo)
[   27.426394] cloud-init[1017]: --> python2-jmespath-0.9.3-1.amzn2.0.1.noarch from @amzn2-core removed (updateinfo)
[   27.426473] cloud-init[1017]: --> libblkid-2.30.2-2.amzn2.0.7.aarch64 from installed removed (updateinfo)
[   27.426551] cloud-init[1017]: --> e2fsprogs-libs-1.42.9-19.amzn2.0.1.aarch64 from amzn2-core removed (updateinfo)
[   27.426632] cloud-init[1017]: --> nspr-4.32.0-1.amzn2.0.1.aarch64 from installed removed (updateinfo)
[   27.426712] cloud-init[1017]: --> libsmartcols-2.30.2-2.amzn2.0.10.aarch64 from amzn2-core removed (updateinfo)
[   27.426798] cloud-init[1017]: --> 12:dhcp-common-4.2.5-79.amzn2.1.1.aarch64 from installed removed (updateinfo)
[   27.426879] cloud-init[1017]: --> libuuid-2.30.2-2.amzn2.0.10.aarch64 from amzn2-core removed (updateinfo)
[   27.426960] cloud-init[1017]: --> ncurses-base-6.0-8.20170212.amzn2.1.3.noarch from installed removed (updateinfo)
[   27.427040] cloud-init[1017]: --> systemd-libs-219-78.amzn2.0.21.aarch64 from amzn2-core removed (updateinfo)
[   27.427120] cloud-init[1017]: --> python-colorama-0.3.2-3.amzn2.noarch from @amzn2-core removed (updateinfo)
[   27.427195] cloud-init[1017]: --> util-linux-2.30.2-2.amzn2.0.7.aarch64 from installed removed (updateinfo)
[   27.427271] cloud-init[1017]: --> python2-pyasn1-0.1.9-7.amzn2.0.2.noarch from amzn2-core removed (updateinfo)
[   27.427355] cloud-init[1017]: --> libss-1.42.9-19.amzn2.aarch64 from installed removed (updateinfo)
[   27.427436] cloud-init[1017]: --> python2-rsa-3.4.1-1.amzn2.0.1.noarch from @amzn2-core removed (updateinfo)
[   27.481057] cloud-init[1017]: --> 12:dhcp-common-4.2.5-79.amzn2.1.2.aarch64 from amzn2-core removed (updateinfo)
[   27.481253] cloud-init[1017]: --> libcrypt-2.26-62.amzn2.aarch64 from amzn2-core removed (updateinfo)
[   27.481415] cloud-init[1017]: --> nss-sysinit-3.67.0-4.amzn2.0.2.aarch64 from installed removed (updateinfo)
[   27.481623] cloud-init[1017]: --> curl-7.79.1-7.amzn2.0.1.aarch64 from amzn2-core removed (updateinfo)
[   27.481774] cloud-init[1017]: --> e2fsprogs-1.42.9-19.amzn2.0.1.aarch64 from amzn2-core removed (updateinfo)
[   27.481958] cloud-init[1017]: --> libfdisk-2.30.2-2.amzn2.0.7.aarch64 from installed removed (updateinfo)
[   27.482124] cloud-init[1017]: --> nss-softokn-freebl-3.67.0-3.amzn2.0.1.aarch64 from installed removed (updateinfo)
[   27.482304] cloud-init[1017]: --> nss-util-3.67.0-1.amzn2.0.1.aarch64 from installed removed (updateinfo)
[   27.482468] cloud-init[1017]: --> ncurses-libs-6.0-8.20170212.amzn2.1.4.aarch64 from amzn2-core removed (updateinfo)
[   27.482646] cloud-init[1017]: --> python2-jsonschema-2.5.1-3.amzn2.0.1.noarch from installed removed (updateinfo)
[   27.482811] cloud-init[1017]: --> glibc-locale-source-2.26-61.amzn2.aarch64 from @amzn2-core removed (updateinfo)
[   27.482979] cloud-init[1017]: --> libsmartcols-2.30.2-2.amzn2.0.7.aarch64 from installed removed (updateinfo)
[   27.483150] cloud-init[1017]: --> libmount-2.30.2-2.amzn2.0.7.aarch64 from installed removed (updateinfo)
[   27.483324] cloud-init[1017]: --> 12:dhcp-libs-4.2.5-79.amzn2.1.2.aarch64 from amzn2-core removed (updateinfo)
[   27.483493] cloud-init[1017]: --> nss-softokn-freebl-3.79.0-4.amzn2.aarch64 from amzn2-core removed (updateinfo)
[   27.483668] cloud-init[1017]: --> libmount-2.30.2-2.amzn2.0.10.aarch64 from amzn2-core removed (updateinfo)
[   27.483836] cloud-init[1017]: --> nss-tools-3.67.0-4.amzn2.0.2.aarch64 from installed removed (updateinfo)
[   27.484007] cloud-init[1017]: --> libblkid-2.30.2-2.amzn2.0.10.aarch64 from amzn2-core removed (updateinfo)
[   27.484177] cloud-init[1017]: --> glibc-2.26-61.amzn2.aarch64 from @amzn2-core removed (updateinfo)
[   27.484346] cloud-init[1017]: --> systemd-219-78.amzn2.0.21.aarch64 from amzn2-core removed (updateinfo)
[   27.484517] cloud-init[1017]: --> python-six-1.9.0-2.amzn2.noarch from installed removed (updateinfo)
[   27.484686] cloud-init[1017]: --> tzdata-2022f-1.amzn2.0.1.noarch from amzn2-core removed (updateinfo)
[   27.484857] cloud-init[1017]: --> ncurses-6.0-8.20170212.amzn2.1.3.aarch64 from installed removed (updateinfo)
[   27.485033] cloud-init[1017]: --> glibc-locale-source-2.26-62.amzn2.aarch64 from amzn2-core removed (updateinfo)
[   27.485208] cloud-init[1017]: --> 1:python2-dateutil-2.6.0-3.amzn2.0.1.noarch from @amzn2-core removed (updateinfo)
[   27.485383] cloud-init[1017]: --> systemd-sysv-219-78.amzn2.0.20.aarch64 from installed removed (updateinfo)
[   27.485551] cloud-init[1017]: --> libcurl-7.79.1-7.amzn2.0.1.aarch64 from amzn2-core removed (updateinfo)
[   27.485725] cloud-init[1017]: --> libcrypt-2.26-61.amzn2.aarch64 from @amzn2-core removed (updateinfo)
[   27.485909] cloud-init[1017]: --> libfdisk-2.30.2-2.amzn2.0.10.aarch64 from amzn2-core removed (updateinfo)
[   27.486062] cloud-init[1017]: --> libss-1.42.9-19.amzn2.0.1.aarch64 from amzn2-core removed (updateinfo)
[   27.486233] cloud-init[1017]: --> xfsprogs-5.0.0-10.amzn2.0.1.aarch64 from amzn2-core removed (updateinfo)
[   27.486397] cloud-init[1017]: --> python2-six-1.11.0-8.amzn2.0.1.noarch from amzn2-core removed (updateinfo)
[   27.486570] cloud-init[1017]: --> glibc-common-2.26-61.amzn2.aarch64 from @amzn2-core removed (updateinfo)
[   27.486741] cloud-init[1017]: --> nss-3.79.0-4.amzn2.aarch64 from amzn2-core removed (updateinfo)
[   27.486917] cloud-init[1017]: --> e2fsprogs-1.42.9-19.amzn2.aarch64 from installed removed (updateinfo)
[   27.487085] cloud-init[1017]: --> systemd-219-78.amzn2.0.20.aarch64 from installed removed (updateinfo)
[   27.487254] cloud-init[1017]: --> nss-softokn-3.79.0-4.amzn2.aarch64 from amzn2-core removed (updateinfo)
[   27.487432] cloud-init[1017]: --> util-linux-2.30.2-2.amzn2.0.10.aarch64 from amzn2-core removed (updateinfo)
[   27.487601] cloud-init[1017]: --> xfsprogs-4.5.0-18.amzn2.0.1.aarch64 from installed removed (updateinfo)
[   27.487773] cloud-init[1017]: --> systemd-sysv-219-78.amzn2.0.21.aarch64 from amzn2-core removed (updateinfo)
[   27.487937] cloud-init[1017]: --> libuuid-2.30.2-2.amzn2.0.7.aarch64 from installed removed (updateinfo)
[   27.529340] cloud-init[1017]: --> 12:dhclient-4.2.5-79.amzn2.1.1.aarch64 from installed removed (updateinfo)
[   27.529430] cloud-init[1017]: --> libcom_err-1.42.9-19.amzn2.0.1.aarch64 from amzn2-core removed (updateinfo)
[   27.529599] cloud-init[1017]: --> curl-7.79.1-4.amzn2.0.1.aarch64 from installed removed (updateinfo)
[   27.529766] cloud-init[1017]: --> glibc-common-2.26-62.amzn2.aarch64 from amzn2-core removed (updateinfo)
[   27.529933] cloud-init[1017]: --> nss-3.67.0-4.amzn2.0.2.aarch64 from installed removed (updateinfo)
[   27.530105] cloud-init[1017]: --> libcurl-7.79.1-4.amzn2.0.1.aarch64 from installed removed (updateinfo)
[   27.530281] cloud-init[1017]: --> systemd-libs-219-78.amzn2.0.20.aarch64 from installed removed (updateinfo)
[   27.530450] cloud-init[1017]: --> nss-softokn-3.67.0-3.amzn2.0.1.aarch64 from installed removed (updateinfo)
[   27.530616] cloud-init[1017]: --> python2-pyasn1-0.1.9-7.amzn2.0.1.noarch from installed removed (updateinfo)
[   27.530808] cloud-init[1017]: --> ncurses-6.0-8.20170212.amzn2.1.4.aarch64 from amzn2-core removed (updateinfo)
[   27.530974] cloud-init[1017]: 9 package(s) needed (+0 related) for security, out of 54 available
[   27.531132] cloud-init[1017]: Resolving Dependencies
[   27.531305] cloud-init[1017]: --> Running transaction check
[   27.531473] cloud-init[1017]: ---> Package dbus.aarch64 1:1.10.24-7.amzn2 will be updated
[   27.531656] cloud-init[1017]: ---> Package dbus.aarch64 1:1.10.24-7.amzn2.0.2 will be an update
[   27.560026] cloud-init[1017]: ---> Package dbus-libs.aarch64 1:1.10.24-7.amzn2 will be updated
[   27.561730] cloud-init[1017]: ---> Package dbus-libs.aarch64 1:1.10.24-7.amzn2.0.2 will be an update
[   27.565621] cloud-init[1017]: ---> Package expat.aarch64 0:2.1.0-14.amzn2.0.1 will be updated
[   27.569614] cloud-init[1017]: ---> Package expat.aarch64 0:2.1.0-15.amzn2.0.2 will be an update
[   27.571220] cloud-init[1017]: ---> Package kpartx.aarch64 0:0.4.9-127.amzn2 will be updated
[   27.573567] cloud-init[1017]: ---> Package kpartx.aarch64 0:0.4.9-136.amzn2 will be an update
[   27.576648] cloud-init[1017]: ---> Package libtiff.aarch64 0:4.0.3-35.amzn2.0.2 will be updated
[   27.583319] cloud-init[1017]: ---> Package libtiff.aarch64 0:4.0.3-35.amzn2.0.5 will be an update
[   27.590796] cloud-init[1017]: ---> Package python3.aarch64 0:3.7.10-1.amzn2.0.1 will be updated
[   27.600111] cloud-init[1017]: ---> Package python3.aarch64 0:3.7.15-1.amzn2.0.2 will be an update
[   27.609713] cloud-init[1017]: ---> Package python3-libs.aarch64 0:3.7.10-1.amzn2.0.1 will be updated
[   27.611822] cloud-init[1017]: ---> Package python3-libs.aarch64 0:3.7.15-1.amzn2.0.2 will be an update
[   27.638988] cloud-init[1017]: ---> Package vim-data.noarch 2:9.0.475-1.amzn2.0.1 will be updated
[   27.641871] cloud-init[1017]: ---> Package vim-data.noarch 2:9.0.828-1.amzn2.0.1 will be an update
[   27.643235] cloud-init[1017]: ---> Package vim-minimal.aarch64 2:9.0.475-1.amzn2.0.1 will be updated
[   27.645619] cloud-init[1017]: ---> Package vim-minimal.aarch64 2:9.0.828-1.amzn2.0.1 will be an update
[   28.167933] cloud-init[1017]: --> Finished Dependency Resolution
[   28.194564] cloud-init[1017]: Dependencies Resolved
[   28.197835] cloud-init[1017]: ================================================================================
[   28.199391] cloud-init[1017]: Package          Arch        Version                      Repository      Size
[   28.200581] cloud-init[1017]: ================================================================================
[   28.200828] cloud-init[1017]: Updating:
[   28.200919] cloud-init[1017]: dbus             aarch64     1:1.10.24-7.amzn2.0.2        amzn2-core     244 k
[   28.200999] cloud-init[1017]: dbus-libs        aarch64     1:1.10.24-7.amzn2.0.2        amzn2-core     167 k
[   28.201081] cloud-init[1017]: expat            aarch64     2.1.0-15.amzn2.0.2           amzn2-core      88 k
[   28.201164] cloud-init[1017]: kpartx           aarch64     0.4.9-136.amzn2              amzn2-core      81 k
[   28.201249] cloud-init[1017]: libtiff          aarch64     4.0.3-35.amzn2.0.5           amzn2-core     172 k
[   28.201328] cloud-init[1017]: python3          aarch64     3.7.15-1.amzn2.0.2           amzn2-core      72 k
[   28.201405] cloud-init[1017]: python3-libs     aarch64     3.7.15-1.amzn2.0.2           amzn2-core     9.7 M
[   28.201485] cloud-init[1017]: vim-data         noarch      2:9.0.828-1.amzn2.0.1        amzn2-core      77 k
[   28.201563] cloud-init[1017]: vim-minimal      aarch64     2:9.0.828-1.amzn2.0.1        amzn2-core     710 k
[   28.201643] cloud-init[1017]: Transaction Summary
[   28.201723] cloud-init[1017]: ================================================================================
[   28.201800] cloud-init[1017]: Upgrade  9 Packages
[   28.201905] cloud-init[1017]: Total download size: 11 M
[   28.201989] cloud-init[1017]: Downloading packages:
[   28.326916] cloud-init[1017]: Delta RPMs disabled because /usr/bin/applydeltarpm not installed.
[   28.579689] cloud-init[1017]: --------------------------------------------------------------------------------
[   28.581435] cloud-init[1017]: Total                                               45 MB/s |  11 MB  00:00
[   28.692086] cloud-init[1017]: Running transaction check
[   28.789143] cloud-init[1017]: Running transaction test
[   29.298684] cloud-init[1017]: Transaction test succeeded
[   29.299860] cloud-init[1017]: Running transaction
[   31.405796] cloud-init[1017]: Updating   : expat-2.1.0-15.amzn2.0.2.aarch64                            1/18
[   31.469522] cloud-init[1017]: Updating   : python3-libs-3.7.15-1.amzn2.0.2.aarch64                     2/18
[   31.489987] cloud-init[1017]: Updating   : python3-3.7.15-1.amzn2.0.2.aarch64                          3/18
[   31.518122] cloud-init[1017]: Updating   : 2:vim-data-9.0.828-1.amzn2.0.1.noarch                       4/18
[   31.583657] cloud-init[1017]: Updating   : 1:dbus-libs-1.10.24-7.amzn2.0.2.aarch64                     5/18
[   31.658373] cloud-init[1017]: Updating   : 1:dbus-1.10.24-7.amzn2.0.2.aarch64                          6/18
[   31.695361] cloud-init[1017]: Updating   : 2:vim-minimal-9.0.828-1.amzn2.0.1.aarch64                   7/18
[   31.725472] cloud-init[1017]: Updating   : libtiff-4.0.3-35.amzn2.0.5.aarch64                          8/18
[   31.746455] cloud-init[1017]: Updating   : kpartx-0.4.9-136.amzn2.aarch64                              9/18
[   31.911537] cloud-init[1017]: Cleanup    : 1:dbus-1.10.24-7.amzn2.aarch64                             10/18
[   31.962376] cloud-init[1017]: Cleanup    : python3-libs-3.7.10-1.amzn2.0.1.aarch64                    11/18
[   31.981387] cloud-init[1017]: Cleanup    : python3-3.7.10-1.amzn2.0.1.aarch64                         12/18
[   32.003257] cloud-init[1017]: Cleanup    : 2:vim-minimal-9.0.475-1.amzn2.0.1.aarch64                  13/18
[   32.021133] cloud-init[1017]: Cleanup    : 2:vim-data-9.0.475-1.amzn2.0.1.noarch                      14/18
[   32.049522] cloud-init[1017]: Cleanup    : expat-2.1.0-14.amzn2.0.1.aarch64                           15/18
[   32.075346] cloud-init[1017]: Cleanup    : 1:dbus-libs-1.10.24-7.amzn2.aarch64                        16/18
[   32.100039] cloud-init[1017]: Cleanup    : libtiff-4.0.3-35.amzn2.0.2.aarch64                         17/18
[   32.129002] cloud-init[1017]: Cleanup    : kpartx-0.4.9-127.amzn2.aarch64                             18/18
[�[32m  OK  �[0m] Stopped Dynamically Generate Message Of The Day.
         Starting Dynamically Generate Message Of The Day...
[   32.148654] cloud-init[1017]: Verifying  : python3-3.7.15-1.amzn2.0.2.aarch64                          1/18
[   32.158132] cloud-init[1017]: Verifying  : kpartx-0.4.9-136.amzn2.aarch64                              2/18
[   32.168698] cloud-init[1017]: Verifying  : 2:vim-minimal-9.0.828-1.amzn2.0.1.aarch64                   3/18
[   32.178210] cloud-init[1017]: Verifying  : 1:dbus-libs-1.10.24-7.amzn2.0.2.aarch64                     4/18
[   32.186404] cloud-init[1017]: Verifying  : expat-2.1.0-15.amzn2.0.2.aarch64                            5/18
[   32.196219] cloud-init[1017]: Verifying  : 1:dbus-1.10.24-7.amzn2.0.2.aarch64                          6/18
[   32.206866] cloud-init[1017]: Verifying  : 2:vim-data-9.0.828-1.amzn2.0.1.noarch                       7/18
[   32.216599] cloud-init[1017]: Verifying  : python3-libs-3.7.15-1.amzn2.0.2.aarch64                     8/18
[   32.226516] cloud-init[1017]: Verifying  : libtiff-4.0.3-35.amzn2.0.5.aarch64                          9/18
[   32.228326] cloud-init[1017]: Verifying  : expat-2.1.0-14.amzn2.0.1.aarch64                           10/18
[   32.230777] cloud-init[1017]: Verifying  : libtiff-4.0.3-35.amzn2.0.2.aarch64                         11/18
[   32.232432] cloud-init[1017]: Verifying  : 1:dbus-libs-1.10.24-7.amzn2.aarch64                        12/18
[   32.234075] cloud-init[1017]: Verifying  : 1:dbus-1.10.24-7.amzn2.aarch64                             13/18
[   32.236239] cloud-init[1017]: Verifying  : python3-libs-3.7.10-1.amzn2.0.1.aarch64                    14/18
[   32.238536] cloud-init[1017]: Verifying  : 2:vim-minimal-9.0.475-1.amzn2.0.1.aarch64                  15/18
[   32.239495] cloud-init[1017]: Verifying  : 2:vim-data-9.0.475-1.amzn2.0.1.noarch                      16/18
[   32.240532] cloud-init[1017]: Verifying  : python3-3.7.10-1.amzn2.0.1.aarch64                         17/18
[   32.295782] cloud-init[1017]: Verifying  : kpartx-0.4.9-127.amzn2.aarch64                             18/18
[   32.297186] cloud-init[1017]: Updated:
[   32.297754] cloud-init[1017]: dbus.aarch64 1:1.10.24-7.amzn2.0.2
[   32.298583] cloud-init[1017]: dbus-libs.aarch64 1:1.10.24-7.amzn2.0.2
[   32.298677] cloud-init[1017]: expat.aarch64 0:2.1.0-15.amzn2.0.2
[   32.298760] cloud-init[1017]: kpartx.aarch64 0:0.4.9-136.amzn2
[   32.298841] cloud-init[1017]: libtiff.aarch64 0:4.0.3-35.amzn2.0.5
[   32.298922] cloud-init[1017]: python3.aarch64 0:3.7.15-1.amzn2.0.2
[   32.299001] cloud-init[1017]: python3-libs.aarch64 0:3.7.15-1.amzn2.0.2
[   32.299081] cloud-init[1017]: vim-data.noarch 2:9.0.828-1.amzn2.0.1
[   32.299157] cloud-init[1017]: vim-minimal.aarch64 2:9.0.828-1.amzn2.0.1
[   32.299663] cloud-init[1017]: Complete!
[�[32m  OK  �[0m] Started Apply the settings specified in cloud-config.
         Starting Execute cloud user/final scripts...
[   32.711475] cloud-init[1158]: Cloud-init v. 19.3-46.amzn2 running 'modules:final' at Thu, 22 Dec 2022 11:27:48 +0000. Up 32.65 seconds.
[   32.724833] cloud-init[1158]: + ...
[   32.740995] cloud-init[1158]: + /etc/eks/bootstrap.sh eks-dev --b64-cluster-ca ...
[   33.602502] cloud-init[1158]: Using kubelet version 1.23.9
[   33.607378] cloud-init[1158]: Using dockerd as the container runtime
[   33.732573] cloud-init[1158]: â��/etc/eks/iptables-restore.serviceâ�� -> â��/etc/systemd/system/iptables-restore.serviceâ��
[�[32m  OK  �[0m] Created slice User Slice of root.
[�[32m  OK  �[0m] Started Session c1 of user root.
[�[32m  OK  �[0m] Removed slice User Slice of root.
[   33.938975] cloud-init[1158]: Created symlink from /etc/systemd/system/multi-user.target.wants/iptables-restore.service to /etc/systemd/system/iptables-restore.service.
[   34.237686] cloud-init[1158]: Created symlink from /etc/systemd/system/multi-user.target.wants/docker.service to /usr/lib/systemd/system/docker.service.
         Starting containerd container runtime...
         Starting Docker Socket for the API.
[�[32m  OK  �[0m] Listening on Docker Socket for the API.
[�[32m  OK  �[0m] Started containerd container runtime.
         Starting Docker Application Container Engine...
[�[32m  OK  �[0m] Started Dynamically Generate Message Of The Day.
[   36.493079] bpfilter: Loaded bpfilter_umh pid 1396
[   36.493253] Started bpfilter
[�[32m  OK  �[0m] Started Docker Application Container Engine.
[�[32m  OK  �[0m] Reached target Multi-User System.
[�[32m  OK  �[0m] Reached target Graphical Interface.
         Starting Update UTMP about System Runlevel Changes...
[   37.211557] cloud-init[1158]: Created symlink from /etc/systemd/system/multi-user.target.wants/kubelet.service to /etc/systemd/system/kubelet.service.
[�[32m  OK  �[0m] Started Update UTMP about System Runlevel Changes.
         Starting Kubernetes Kubelet...
[�[32m  OK  �[0m] Started Kubernetes Kubelet.
[   37.334039] cloud-init[1158]: nvidia-smi not found
[   37.335593] cloud-init[1158]: ci-info: no authorized ssh keys fingerprints found for user ec2-user.
ci-info: no authorized ssh keys fingerprints found for user ec2-user.
<14>Dec 22 11:27:53 ec2: 
<14>Dec 22 11:27:53 ec2: #############################################################
<14>Dec 22 11:27:53 ec2: -----BEGIN SSH HOST KEY FINGERPRINTS-----
<14>Dec 22 11:27:53 ec2: -----END SSH HOST KEY FINGERPRINTS-----
<14>Dec 22 11:27:53 ec2: #############################################################
-----BEGIN SSH HOST KEY KEYS-----

[   37.378101] cloud-init[1158]: Cloud-init v. 19.3-46.amzn2 finished at Thu, 22 Dec 2022 11:27:53 +0000. Datasource DataSourceEc2.  Up 37.37 seconds
[�[32m  OK  �[0m] Started Execute cloud user/final scripts.
[�[32m  OK  �[0m] Reached target Cloud-init target.
[   40.497668] cgroup: cgroup: disabling cgroup2 socket matching due to net_prio or net_cls activation
[   42.459919] IPVS: Registered protocols (TCP, UDP, SCTP, AH, ESP)
[   42.460881] IPVS: Connection hash table configured (size=4096, memory=32Kbytes)
[   42.462066] IPVS: ipvs loaded.
[   42.465171] IPVS: [rr] scheduler registered.
[   42.469202] IPVS: [wrr] scheduler registered.
[   42.472244] IPVS: [sh] scheduler registered.
[   77.246088] xfs filesystem being remounted at /var/lib/kubelet/pods/4116baf8-8459-4e29-890d-bd4335b72a94/volume-subpaths/nri-kubernetes-config/kubelet/0 supports timestamps until 2038 (0x7fffffff)
[   97.473574] xfs filesystem being remounted at /var/lib/kubelet/pods/4116baf8-8459-4e29-890d-bd4335b72a94/volume-subpaths/config/agent/0 supports timestamps until 2038 (0x7fffffff)

njtran · 2022-12-22T19:26:43Z

Hey @royb-tabit, thanks for the loads of information! By chance do you know what you've changed since the setup to make your node startup time go from 60s to 100s? Have you changed the AMI, the user data, or added more pod/node constraints? If it hasn't been at 60s at all, that'd be good to know too.

royb-tabit · 2022-12-25T08:44:24Z

Hey @njtran, Thanks for your question. We never got to see karpenter
finish at 60s, the only reference I have is our aws-node-autoscaler that
use the same user-data and image. it take him about 65s-70s, and
it seems that once the kube-proxy start (on aws-node-autoscaler)
it gos to 'ready state' much faster.

bwagner5 · 2022-12-27T20:00:30Z

The discrepancy may be that Karpenter creates the node right when the instance is launched and the cluster-autoscaler will wait for the kubelet to come online to register the node with the API server which will make it look like the node came online faster, but the actual time between the EC2 instance being launched and the node going Ready should be mostly the same between Karpenter and Cluster Autoscaler.

royb-tabit · 2022-12-28T09:37:36Z

Hey @bwagner5,
We started timing the cluster-autoscaler from the instance
creation on AWS (it takes for the instance to register about 30s,
after that about 25s for kube-proxy to start and 10s for the Node
to be Ready - overall 65s)

bwagner5 · 2022-12-28T15:09:27Z

@royb-tabit Would you be able to run this node timing tool that we recently open sourced on both the node launched by Karpenter and the node launched by cluster-autoscaler? https://github.com/awslabs/node-latency-for-k8s

You can run the binary on the node after the instance is launched or you can run it as a DaemonSet. If you can post the timing chart that the tool produces on stdout, that may help narrow down the issue.

royb-tabit · 2023-01-01T09:28:02Z

Hey @bwagner5 ,
Sure that sounds great.
I'll get back with the results.

royb-tabit · 2023-01-03T09:50:08Z

Hey @bwagner5 , I ran the DeamonSet, but it had some issues connecting the data, do you have an idea why?

EDIT:
These logs are from Karpenter Node, I will make one for AWS ClusterAutoscaler as well.

2023/01/03 09:29:11 Unable to retrieve timing for Event "Kube-APIServer Throttled": no matches in /var/log/messages* for regex ".*Waited for .* due to client-side throttling, not priority and fairness, request: .*"
2023/01/03 09:29:11 Unable to retrieve timing for Event "Fleet Requested": operation error EC2: DescribeTags, failed to resolve service endpoint, an AWS region is required, but was not found
2023/01/03 09:29:11 Unable to retrieve timing for Event "Pod Ready": no matches in /var/log/messages* for regex ".*default/.* Type:ContainerStarted.*"
2023/01/03 09:29:17 Unable to retrieve timing for Event "Kube-APIServer Throttled": no matches in /var/log/messages* for regex ".*Waited for .* due to client-side throttling, not priority and fairness, request: .*"
2023/01/03 09:29:17 Unable to retrieve timing for Event "Fleet Requested": operation error EC2: DescribeTags, failed to resolve service endpoint, an AWS region is required, but was not found
2023/01/03 09:29:17 Unable to retrieve timing for Event "Pod Ready": no matches in /var/log/messages* for regex ".*default/.* Type:ContainerStarted.*"
2023/01/03 09:29:23 Unable to retrieve timing for Event "Kube-APIServer Throttled": no matches in /var/log/messages* for regex ".*Waited for .* due to client-side throttling, not priority and fairness, request: .*"
2023/01/03 09:29:23 Unable to retrieve timing for Event "Fleet Requested": operation error EC2: DescribeTags, failed to resolve service endpoint, an AWS region is required, but was not found
2023/01/03 09:29:23 Unable to retrieve timing for Event "Pod Ready": no matches in /var/log/messages* for regex ".*default/.* Type:ContainerStarted.*"
2023/01/03 09:29:29 Unable to retrieve timing for Event "Kube-APIServer Throttled": no matches in /var/log/messages* for regex ".*Waited for .* due to client-side throttling, not priority and fairness, request: .*"
2023/01/03 09:29:29 Unable to retrieve timing for Event "Fleet Requested": operation error EC2: DescribeTags, failed to resolve service endpoint, an AWS region is required, but was not found
2023/01/03 09:29:29 Unable to retrieve timing for Event "Pod Ready": no matches in /var/log/messages* for regex ".*default/.* Type:ContainerStarted.*"
2023/01/03 09:29:36 Unable to retrieve timing for Event "Kube-APIServer Throttled": no matches in /var/log/messages* for regex ".*Waited for .* due to client-side throttling, not priority and fairness, request: .*"
2023/01/03 09:29:36 Unable to retrieve timing for Event "Fleet Requested": operation error EC2: DescribeTags, failed to resolve service endpoint, an AWS region is required, but was not found
2023/01/03 09:29:36 Unable to retrieve timing for Event "Pod Ready": no matches in /var/log/messages* for regex ".*default/.* Type:ContainerStarted.*"
2023/01/03 09:29:41 unable to measure terminal events: []
2023/01/03 09:29:41 Error with event "Kube-APIServer Throttled" timing: no matches in /var/log/messages* for regex ".*Waited for .* due to client-side throttling, not priority and fairness, request: .*"
2023/01/03 09:29:41 Error with event "Fleet Requested" timing: operation error EC2: DescribeTags, failed to resolve service endpoint, an AWS region is required, but was not found
2023/01/03 09:29:41 Error with event "Pod Ready" timing: no matches in /var/log/messages* for regex ".*default/.* Type:ContainerStarted.*"
2023/01/03 09:29:41 Error emitting CloudWatch metrics: operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found
2023/01/03 09:29:41 Serving Prometheus metrics on :2112
### i-03ede22dbea2d9533 (10.2.25.151) | t3a.large | x86_64 | eu-west-1c | ami-0b55230f107a87100
|           EVENT            |      TIMESTAMP       |      T      | COMMENT |
|----------------------------|----------------------|-------------|---------|
| Pod Created                | 0001-01-01T00:00:00Z | 0s          |         |
| Instance Pending           | 2023-01-03T09:27:38Z | 9223372037s |         |
| VM Initialized             | 2023-01-03T09:27:48Z | 9223372037s |         |
| Network Start              | 2023-01-03T09:27:58Z | 9223372037s |         |
| Network Ready              | 2023-01-03T09:27:59Z | 9223372037s |         |
| Cloud-Init Initial Start   | 2023-01-03T09:27:59Z | 9223372037s |         |
| Cloud-Init Config Start    | 2023-01-03T09:28:01Z | 9223372037s |         |
| Cloud-Init Final Start     | 2023-01-03T09:28:17Z | 9223372037s |         |
| Containerd Start           | 2023-01-03T09:28:24Z | 9223372037s |         |
| Containerd Initialized     | 2023-01-03T09:28:27Z | 9223372037s |         |
| Kubelet Start              | 2023-01-03T09:28:32Z | 9223372037s |         |
| Cloud-Init Final Finish    | 2023-01-03T09:28:32Z | 9223372037s |         |
| Kubelet Initialized        | 2023-01-03T09:28:38Z | 9223372037s |         |
| Kubelet Registered         | 2023-01-03T09:28:39Z | 9223372037s |         |
| Kube-Proxy Start           | 2023-01-03T09:28:43Z | 9223372037s |         |
| VPC CNI Init Start         | 2023-01-03T09:28:47Z | 9223372037s |         |
| AWS Node Start             | 2023-01-03T09:28:57Z | 9223372037s |         |
| VPC CNI Plugin Initialized | 2023-01-03T09:28:58Z | 9223372037s |         |
| Node Ready                 | 2023-01-03T09:29:10Z | 9223372037s |         |

royb-tabit · 2023-01-03T10:25:14Z

These are the AWS ClusterAutoscaler logs:

2023/01/03 10:22:35 Unable to retrieve timing for Event "Kube-Proxy Start": no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:kube-proxy.* returns container id.*"
2023/01/03 10:22:35 Unable to retrieve timing for Event "Fleet Requested": operation error EC2: DescribeTags, failed to resolve service endpoint, an AWS region is required, but was not found
2023/01/03 10:22:35 Unable to retrieve timing for Event "Pod Ready": no matches in /var/log/messages* for regex ".*default/.* Type:ContainerStarted.*"
2023/01/03 10:22:35 Unable to retrieve timing for Event "Kube-APIServer Throttled": no matches in /var/log/messages* for regex ".*Waited for .* due to client-side throttling, not priority and fairness, request: .*"
2023/01/03 10:22:35 Unable to retrieve timing for Event "VPC CNI Plugin Initialized": unable to open log file /var/log/pods/kube-system_aws-node-kg5w6_8db9b5c6-2a38-43f7-950f-85ee79e15338/aws-node/0.log: open /var/log/pods/kube-system_aws-node-kg5w6_8db9b5c6-2a38-43f7-950f-85ee79e15338/aws-node/0.log: no such file or directory
2023/01/03 10:22:35 Unable to retrieve timing for Event "AWS Node Start": no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:aws-node.* returns container id.*"
2023/01/03 10:22:35 Unable to retrieve timing for Event "VPC CNI Init Start": no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:aws-vpc-cni-init.* returns container id.*"
2023/01/03 10:22:40 Unable to retrieve timing for Event "Kube-Proxy Start": no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:kube-proxy.* returns container id.*"
2023/01/03 10:22:40 Unable to retrieve timing for Event "Fleet Requested": operation error EC2: DescribeTags, failed to resolve service endpoint, an AWS region is required, but was not found
2023/01/03 10:22:40 Unable to retrieve timing for Event "Pod Ready": no matches in /var/log/messages* for regex ".*default/.* Type:ContainerStarted.*"
2023/01/03 10:22:40 Unable to retrieve timing for Event "Kube-APIServer Throttled": no matches in /var/log/messages* for regex ".*Waited for .* due to client-side throttling, not priority and fairness, request: .*"
2023/01/03 10:22:40 Unable to retrieve timing for Event "VPC CNI Plugin Initialized": unable to open log file /var/log/pods/kube-system_aws-node-kg5w6_8db9b5c6-2a38-43f7-950f-85ee79e15338/aws-node/0.log: open /var/log/pods/kube-system_aws-node-kg5w6_8db9b5c6-2a38-43f7-950f-85ee79e15338/aws-node/0.log: no such file or directory
2023/01/03 10:22:40 Unable to retrieve timing for Event "AWS Node Start": no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:aws-node.* returns container id.*"
2023/01/03 10:22:40 Unable to retrieve timing for Event "VPC CNI Init Start": no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:aws-vpc-cni-init.* returns container id.*"
2023/01/03 10:22:45 Unable to retrieve timing for Event "Kube-Proxy Start": no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:kube-proxy.* returns container id.*"
2023/01/03 10:22:45 Unable to retrieve timing for Event "Fleet Requested": operation error EC2: DescribeTags, failed to resolve service endpoint, an AWS region is required, but was not found
2023/01/03 10:22:45 Unable to retrieve timing for Event "Pod Ready": no matches in /var/log/messages* for regex ".*default/.* Type:ContainerStarted.*"
2023/01/03 10:22:45 Unable to retrieve timing for Event "Kube-APIServer Throttled": no matches in /var/log/messages* for regex ".*Waited for .* due to client-side throttling, not priority and fairness, request: .*"
2023/01/03 10:22:45 Unable to retrieve timing for Event "VPC CNI Plugin Initialized": unable to open log file /var/log/pods/kube-system_aws-node-kg5w6_8db9b5c6-2a38-43f7-950f-85ee79e15338/aws-node/0.log: open /var/log/pods/kube-system_aws-node-kg5w6_8db9b5c6-2a38-43f7-950f-85ee79e15338/aws-node/0.log: no such file or directory
2023/01/03 10:22:45 Unable to retrieve timing for Event "AWS Node Start": no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:aws-node.* returns container id.*"
2023/01/03 10:22:45 Unable to retrieve timing for Event "VPC CNI Init Start": no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:aws-vpc-cni-init.* returns container id.*"
2023/01/03 10:22:51 Unable to retrieve timing for Event "Kube-Proxy Start": no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:kube-proxy.* returns container id.*"
2023/01/03 10:22:51 Unable to retrieve timing for Event "Fleet Requested": operation error EC2: DescribeTags, failed to resolve service endpoint, an AWS region is required, but was not found
2023/01/03 10:22:51 Unable to retrieve timing for Event "Pod Ready": no matches in /var/log/messages* for regex ".*default/.* Type:ContainerStarted.*"
2023/01/03 10:22:51 Unable to retrieve timing for Event "Kube-APIServer Throttled": no matches in /var/log/messages* for regex ".*Waited for .* due to client-side throttling, not priority and fairness, request: .*"
2023/01/03 10:22:51 Unable to retrieve timing for Event "VPC CNI Plugin Initialized": unable to open log file /var/log/pods/kube-system_aws-node-kg5w6_8db9b5c6-2a38-43f7-950f-85ee79e15338/aws-node/0.log: open /var/log/pods/kube-system_aws-node-kg5w6_8db9b5c6-2a38-43f7-950f-85ee79e15338/aws-node/0.log: no such file or directory
2023/01/03 10:22:51 Unable to retrieve timing for Event "AWS Node Start": no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:aws-node.* returns container id.*"
2023/01/03 10:22:51 Unable to retrieve timing for Event "VPC CNI Init Start": no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:aws-vpc-cni-init.* returns container id.*"
2023/01/03 10:22:56 Unable to retrieve timing for Event "Kube-Proxy Start": no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:kube-proxy.* returns container id.*"
2023/01/03 10:22:56 Unable to retrieve timing for Event "Fleet Requested": operation error EC2: DescribeTags, failed to resolve service endpoint, an AWS region is required, but was not found
2023/01/03 10:22:56 Unable to retrieve timing for Event "Pod Ready": no matches in /var/log/messages* for regex ".*default/.* Type:ContainerStarted.*"
2023/01/03 10:22:56 Unable to retrieve timing for Event "Kube-APIServer Throttled": no matches in /var/log/messages* for regex ".*Waited for .* due to client-side throttling, not priority and fairness, request: .*"
2023/01/03 10:22:56 Unable to retrieve timing for Event "VPC CNI Plugin Initialized": unable to open log file /var/log/pods/kube-system_aws-node-kg5w6_8db9b5c6-2a38-43f7-950f-85ee79e15338/aws-node/0.log: open /var/log/pods/kube-system_aws-node-kg5w6_8db9b5c6-2a38-43f7-950f-85ee79e15338/aws-node/0.log: no such file or directory
2023/01/03 10:22:56 Unable to retrieve timing for Event "AWS Node Start": no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:aws-node.* returns container id.*"
2023/01/03 10:22:56 Unable to retrieve timing for Event "VPC CNI Init Start": no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:aws-vpc-cni-init.* returns container id.*"
2023/01/03 10:23:01 Unable to retrieve timing for Event "Kube-Proxy Start": no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:kube-proxy.* returns container id.*"
2023/01/03 10:23:01 Unable to retrieve timing for Event "Fleet Requested": operation error EC2: DescribeTags, failed to resolve service endpoint, an AWS region is required, but was not found
2023/01/03 10:23:01 Unable to retrieve timing for Event "Pod Ready": no matches in /var/log/messages* for regex ".*default/.* Type:ContainerStarted.*"
2023/01/03 10:23:01 Unable to retrieve timing for Event "Kube-APIServer Throttled": no matches in /var/log/messages* for regex ".*Waited for .* due to client-side throttling, not priority and fairness, request: .*"
2023/01/03 10:23:01 Unable to retrieve timing for Event "VPC CNI Plugin Initialized": unable to open log file /var/log/pods/kube-system_aws-node-kg5w6_8db9b5c6-2a38-43f7-950f-85ee79e15338/aws-node/0.log: open /var/log/pods/kube-system_aws-node-kg5w6_8db9b5c6-2a38-43f7-950f-85ee79e15338/aws-node/0.log: no such file or directory
2023/01/03 10:23:01 Unable to retrieve timing for Event "AWS Node Start": no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:aws-node.* returns container id.*"
2023/01/03 10:23:01 Unable to retrieve timing for Event "VPC CNI Init Start": no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:aws-vpc-cni-init.* returns container id.*"
2023/01/03 10:23:06 unable to measure terminal events: []
### i-07d24f53e7c1c879b (10.2.22.234) | t2.large | x86_64 | eu-west-1b | ami-0de933c15c9b49fb5
2023/01/03 10:23:06 Error with event "Kube-Proxy Start" timing: no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:kube-proxy.* returns container id.*"
2023/01/03 10:23:06 Error with event "Fleet Requested" timing: operation error EC2: DescribeTags, failed to resolve service endpoint, an AWS region is required, but was not found
2023/01/03 10:23:06 Error with event "Pod Ready" timing: no matches in /var/log/messages* for regex ".*default/.* Type:ContainerStarted.*"
2023/01/03 10:23:06 Error with event "Kube-APIServer Throttled" timing: no matches in /var/log/messages* for regex ".*Waited for .* due to client-side throttling, not priority and fairness, request: .*"
2023/01/03 10:23:06 Error with event "VPC CNI Plugin Initialized" timing: unable to open log file /var/log/pods/kube-system_aws-node-kg5w6_8db9b5c6-2a38-43f7-950f-85ee79e15338/aws-node/0.log: open /var/log/pods/kube-system_aws-node-kg5w6_8db9b5c6-2a38-43f7-950f-85ee79e15338/aws-node/0.log: no such file or directory
2023/01/03 10:23:06 Error with event "AWS Node Start" timing: no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:aws-node.* returns container id.*"
2023/01/03 10:23:06 Error with event "VPC CNI Init Start" timing: no matches in /var/log/messages* for regex ".*CreateContainer within sandbox .*Name:aws-vpc-cni-init.* returns container id.*"
|          EVENT           |      TIMESTAMP       |      T      | COMMENT |
|--------------------------|----------------------|-------------|---------|
| Pod Created              | 0001-01-01T00:00:00Z | 0s          |         |
| Instance Pending         | 2023-01-03T10:20:59Z | 9223372037s |         |
| VM Initialized           | 2023-01-03T10:21:15Z | 9223372037s |         |
| Network Ready            | 2023-01-03T10:21:19Z | 9223372037s |         |
| Cloud-Init Initial Start | 2023-01-03T10:21:19Z | 9223372037s |         |
| Network Start            | 2023-01-03T10:21:19Z | 9223372037s |         |
| Cloud-Init Config Start  | 2023-01-03T10:21:21Z | 9223372037s |         |
| Cloud-Init Final Start   | 2023-01-03T10:21:32Z | 9223372037s |         |
| Containerd Start         | 2023-01-03T10:21:34Z | 9223372037s |         |
| Containerd Initialized   | 2023-01-03T10:21:35Z | 9223372037s |         |
| Kubelet Start            | 2023-01-03T10:21:38Z | 9223372037s |         |
| Cloud-Init Final Finish  | 2023-01-03T10:21:38Z | 9223372037s |         |
| Kubelet Initialized      | 2023-01-03T10:21:39Z | 9223372037s |         |
| Kubelet Registered       | 2023-01-03T10:21:39Z | 9223372037s |         |
| Node Ready               | 2023-01-03T10:22:10Z | 9223372037s |         |
2023/01/03 10:23:06 Error emitting CloudWatch metrics: operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found; operation error CloudWatch: PutMetricData, failed to resolve service endpoint, an AWS region is required, but was not found
2023/01/03 10:23:06 Serving Prometheus metrics on :2112

ellistarn · 2023-01-03T17:40:45Z

AWS region is required

@bwagner5 is more familiar, but maybe there's a way to set this?

bwagner5 · 2023-01-03T22:01:05Z

Looks like it doesn't have permissions to access the K8s API or AWS APIs. Looks like I missed a README update when I added those events, so you'd need to install it with an IAM role for those events to work.

But most of the data is here.

Cluster Autoscaler Launch-to-Ready:

EVENT	TIMESTAMP	T
Instance Pending	2023-01-03T10:20:59Z	0s
VM Initialized	2023-01-03T10:21:15Z	16s
Network Ready	2023-01-03T10:21:19Z	20s
Cloud-Init Initial Start	2023-01-03T10:21:19Z	20s
Network Start	2023-01-03T10:21:19Z	20s
Cloud-Init Config Start	2023-01-03T10:21:21Z	22s
Cloud-Init Final Start	2023-01-03T10:21:32Z	33s
Containerd Start	2023-01-03T10:21:34Z	35s
Containerd Initialized	2023-01-03T10:21:35Z	36s
Kubelet Start	2023-01-03T10:21:38Z	39s
Cloud-Init Final Finish	2023-01-03T10:21:38Z	39s
Kubelet Initialized	2023-01-03T10:21:39Z	40s
Kubelet Registered	2023-01-03T10:21:39Z	40s
Node Ready	2023-01-03T10:22:10Z	71s

Karpenter Launch-to-Ready:

EVENT	TIMESTAMP	T
Instance Pending	2023-01-03T09:27:38Z	0s
VM Initialized	2023-01-03T09:27:48Z	10s
Network Start	2023-01-03T09:27:58Z	20s
Network Ready	2023-01-03T09:27:59Z	21s
Cloud-Init Initial Start	2023-01-03T09:27:59Z	21s
Cloud-Init Config Start	2023-01-03T09:28:01Z	23s
Cloud-Init Final Start	2023-01-03T09:28:17Z	39s
Containerd Start	2023-01-03T09:28:24Z	46s
Containerd Initialized	2023-01-03T09:28:27Z	49s
Kubelet Start	2023-01-03T09:28:32Z	54s
Cloud-Init Final Finish	2023-01-03T09:28:32Z	54s
Kubelet Initialized	2023-01-03T09:28:38Z	60s
Kubelet Registered	2023-01-03T09:28:39Z	61s
Kube-Proxy Start	2023-01-03T09:28:43Z	65s
VPC CNI Init Start	2023-01-03T09:28:47Z	69s
AWS Node Start	2023-01-03T09:28:57Z	79s
VPC CNI Plugin Initialized	2023-01-03T09:28:58Z	80s
Node Ready	2023-01-03T09:29:10Z	92s

It looks like different AMIs are being used between the CA and Karpenter nodes. The Karpenter one appears to be a slightly older EKS Optimized AL2 AMI compared to the CA one.

One notable different in latency is between the Cloud-init Final Start and Containerd Start (2s vs 7s). Is there a difference in the user-data that is used between CA and Karpenter?

It looks like the CNI wasn't picked up by the node latency tool for Cluster Autoscaler. Are the nodes launched with Cluster Autoscaler using the VPC CNI with a default setup?

I'll also note that t* instance types can have variable startup times. I'd be curious if you see better results on an m6i.large or similar (non-burstable) instance type.

sidewinder12s · 2023-01-14T02:38:19Z

Latest versions of the EKS AMI and the VPC CNI have some optimizations around startup and they appear to actively be tackling startup time.

aws/amazon-vpc-cni-k8s#2138

awslabs/amazon-eks-ami#1099

github-actions · 2023-02-13T12:04:26Z

Labeled for closure due to inactivity in 10 days.

royb-tabit added the bug Something isn't working label Dec 22, 2022

jonathan-innis added the aws label Dec 23, 2022

bwagner5 added question Further information is requested and removed bug Something isn't working labels Jan 23, 2023

github-actions bot added the lifecycle/stale label Feb 13, 2023

github-actions bot added the lifecycle/closed label Feb 24, 2023

github-actions bot closed this as completed Feb 24, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Node take 100s to start #3102

Node take 100s to start #3102

royb-tabit commented Dec 22, 2022

royb-tabit commented Dec 22, 2022

njtran commented Dec 22, 2022

royb-tabit commented Dec 25, 2022

bwagner5 commented Dec 27, 2022

royb-tabit commented Dec 28, 2022

bwagner5 commented Dec 28, 2022

royb-tabit commented Jan 1, 2023

royb-tabit commented Jan 3, 2023 •

edited

Loading

royb-tabit commented Jan 3, 2023

ellistarn commented Jan 3, 2023

bwagner5 commented Jan 3, 2023 •

edited

Loading

sidewinder12s commented Jan 14, 2023

github-actions bot commented Feb 13, 2023

Node take 100s to start #3102

Node take 100s to start #3102

Comments

royb-tabit commented Dec 22, 2022

Version

Expected Behavior

Actual Behavior

Steps to Reproduce the Problem

Resource Specs and Logs

Community Note

royb-tabit commented Dec 22, 2022

njtran commented Dec 22, 2022

royb-tabit commented Dec 25, 2022

bwagner5 commented Dec 27, 2022

royb-tabit commented Dec 28, 2022

bwagner5 commented Dec 28, 2022

royb-tabit commented Jan 1, 2023

royb-tabit commented Jan 3, 2023 • edited Loading

royb-tabit commented Jan 3, 2023

ellistarn commented Jan 3, 2023

bwagner5 commented Jan 3, 2023 • edited Loading

sidewinder12s commented Jan 14, 2023

github-actions bot commented Feb 13, 2023

royb-tabit commented Jan 3, 2023 •

edited

Loading

bwagner5 commented Jan 3, 2023 •

edited

Loading