SELinux "denied" errors

[honarkhah]

Description

Hi, I am trying to integrate the vault-csi-provider into my cluster which I got an error!

│ 2023-04-03T12:01:38.605Z [INFO]  Creating new gRPC server                                                                                                                                                                                                                                           │
│ 2023-04-03T12:01:38.605Z [INFO]  Opening unix socket: endpoint=/provider/vault.sock                                                                                                                                                                                                                 │
│ 2023-04-03T12:01:38.606Z [ERROR] Error running provider: err="failed to listen on unix socket at /provider/vault.sock: listen unix /provider/vault.sock: bind: permission denied"                                                                                                                   │
│ Stream closed EOF for vault/vault-csi-provider-csi-provider-mwtd6 (vault-csi-provider)  

I have checked on the nodes and realized it is not able to create that file on the host os, I just have disabled the policy enforcing to test if that is causing it and was able to run the vault csi provider on the node that setenforce flag was disabled as you can see in below.

Is there any way that I can attach customized policy based on the need?

Kube.tf file

module "kube-hetzner" {

  providers = {
    hcloud = hcloud
  }

  hcloud_token    = var.HCLOUD_TOKEN
  source          = "kube-hetzner/kube-hetzner/hcloud"
  version         = "2.0.2"
  ssh_public_key  = tls_private_key.kube_hetzner.public_key_openssh
  ssh_private_key = tls_private_key.kube_hetzner.private_key_openssh
  network_region  = "eu-central"

  control_plane_nodepools = [
    {
      name        = "control-plane",
      server_type = "cpx11",
      location    = "fsn1",
      labels      = [],
      taints      = [],
      count       = 3
    }
  ]

  agent_nodepools = [
    {
      name        = "worker",
      server_type = "cx51",
      location    = "fsn1",
      labels      = [],
      taints      = [],
      floating_ip = false,
      count       = 3
    }
  ]

  load_balancer_type     = "lb11"
  load_balancer_location = "fsn1"

  ingress_controller        = "none"
  cluster_name              = "test"
  cni_plugin                = "cilium"
  enable_cert_manager       = true
  use_control_plane_lb      = true
  create_kubeconfig         = false
  create_kustomization      = false
  restrict_outbound_traffic = false
}

Screenshots

No response

Platform

Linux

[mysticaltech]

@honarkhah Good catch, please SSH into your node, and execute that command sudo grep "avc: denied" /var/log/audit/audit.log | audit2allow -M my_custom_policy. Then copy paste here the value of your generated my_custom_policy.te file.

Ideally, before that, apply the generate .pp to double check that it works. If not, re-run the command and apply again the .pp, until you get vault working, and then either open a PR with the content of the .te added to the policy section in locals.tf, or just copy it here so that I add it myself.

[mysticaltech]

@honarkhah FYI, you can apply the .pp with semodule -i my_custom_policy.pp.

[mysticaltech]

@honarkhah Any update on this, I await the content of your .te to add it to our kube-hetzner policy so that others can run vault and similar software too.

[honarkhah]

grep "avc: denied" /var/log/audit/audit.log | audit2allow -M my_custom_policy

I have tried it couple of times, but I still get permission denied!

$:~ # grep "avc:  denied" /var/log/audit/audit.log
type=AVC msg=audit(1680592959.117:208937): avc:  denied  { write } for  pid=12053 comm="vault-csi-provi" name="secrets-store-csi-providers" dev="overlay" ino=97 scontext=system_u:system_r:container_t:s0:c735,c822 tcontext=system_u:object_r:etc_t:s0 tclass=dir permissive=0

policy.te file:

module my_custom_policy 1.0;

require {
        type container_t;
        type etc_t;
        class dir { add_name remove_name write };
        class sock_file create;
}

#============= container_t ==============

#!!!! This avc is allowed in the current policy
allow container_t etc_t:dir { add_name remove_name write };

#!!!! This avc is allowed in the current policy
allow container_t etc_t:sock_file create;

But as I see the error in container changed to

[ERROR] Error running provider: err="failed to check for existence of unix socket: stat /provider/vault.sock: permission denied"

[honarkhah]

Ah, finally got it working, the issue was the socket was created before, after deleting and let it to create with new policy it worked, I will create a PR.

module my_custom_policy 1.0;

require {
        type etc_t;
        type container_t;
        class dir { add_name remove_name write };
        class sock_file { create unlink };
}

#============= container_t ==============

#!!!! This avc is allowed in the current policy
allow container_t etc_t:dir { add_name remove_name write };

#!!!! This avc is allowed in the current policy
allow container_t etc_t:sock_file create;
allow container_t etc_t:sock_file unlink;

[michailkorenev]

I have similar problem with the Filebeat. Error from the container:

failed to create Beat meta file: open /usr/share/filebeat/data/meta.json.new: permission denied

Pod's manifest:

apiVersion: v1
kind: Pod
metadata:
  annotations:
    beat.k8s.elastic.co/config-hash: '2123631025'
  creationTimestamp: '2023-04-04T08:33:30Z'
  generateName: filebeat-elk-beat-filebeat-
  labels:
    beat.k8s.elastic.co/name: filebeat-elk
    beat.k8s.elastic.co/version: 8.3.0
    common.k8s.elastic.co/type: beat
    controller-revision-hash: 697549fdf6
    pod-template-generation: '1'
  managedFields:
    - apiVersion: v1
      fieldsType: FieldsV1
      fieldsV1:
        :metadata:
      manager: k3s
      operation: Update
      subresource: status
      time: '2023-04-04T08:36:44Z'
  name: filebeat-elk-beat-filebeat-ctgx5
  namespace: logging
  ownerReferences:
    - apiVersion: apps/v1
      blockOwnerDeletion: true
      controller: true
      kind: DaemonSet
      name: filebeat-elk-beat-filebeat
      uid: aaacb244-8de3-48f8-9c5e-7372a2cc28db
  resourceVersion: '702767'
  uid: 50035b3e-c551-4fc7-8a93-f6cb52862a44
spec:
  affinity:
    nodeAffinity:
      requiredDuringSchedulingIgnoredDuringExecution:
        nodeSelectorTerms:
          - matchFields:
              - key: metadata.name
                operator: In
                values:
                  - k3s-agent-hel1-dnp
  automountServiceAccountToken: true
  containers:
    - args:
        - '-e'
        - '-c'
        - /etc/beat.yml
      env:
        - name: NODE_NAME
          valueFrom:
            fieldRef:
              apiVersion: v1
              fieldPath: spec.nodeName
      image: docker.elastic.co/beats/filebeat:8.3.0
      imagePullPolicy: IfNotPresent
      name: filebeat
      resources:
        limits:
          cpu: 250m
          memory: 500Mi
        requests:
          cpu: 100m
          memory: 200Mi
      securityContext:
        runAsUser: 0
      terminationMessagePath: /dev/termination-log
      terminationMessagePolicy: File
      volumeMounts:
        - mountPath: /usr/share/filebeat/data
          name: beat-data
        - mountPath: /etc/beat.yml
          name: config
          readOnly: true
          subPath: beat.yml
        - mountPath: /var/lib/docker/containers
          name: varlibdockercontainers
        - mountPath: /var/log/containers
          name: varlogcontainers
        - mountPath: /var/log/pods
          name: varlogpods
        - mountPath: /var/run/secrets/kubernetes.io/serviceaccount
          name: kube-api-access-s4rcs
          readOnly: true
  dnsPolicy: ClusterFirstWithHostNet
  enableServiceLinks: true
  hostNetwork: true
  nodeName: k3s-agent-hel1-dnp
  preemptionPolicy: PreemptLowerPriority
  priority: 0
  restartPolicy: Always
  schedulerName: default-scheduler
  securityContext: {}
  serviceAccount: filebeat-elk
  serviceAccountName: filebeat-elk
  terminationGracePeriodSeconds: 30
  tolerations:
    - effect: NoSchedule
      key: dedicated
      operator: Exists
    - effect: NoExecute
      key: node.kubernetes.io/not-ready
      operator: Exists
    - effect: NoExecute
      key: node.kubernetes.io/unreachable
      operator: Exists
    - effect: NoSchedule
      key: node.kubernetes.io/disk-pressure
      operator: Exists
    - effect: NoSchedule
      key: node.kubernetes.io/memory-pressure
      operator: Exists
    - effect: NoSchedule
      key: node.kubernetes.io/pid-pressure
      operator: Exists
    - effect: NoSchedule
      key: node.kubernetes.io/unschedulable
      operator: Exists
    - effect: NoSchedule
      key: node.kubernetes.io/network-unavailable
      operator: Exists
  volumes:
    - hostPath:
        path: /var/lib/logging/filebeat-elk/filebeat-data
        type: DirectoryOrCreate
      name: beat-data
    - name: config
      secret:
        defaultMode: 292
        optional: false
        secretName: filebeat-elk-beat-filebeat-config
    - hostPath:
        path: /var/lib/docker/containers
        type: ''
      name: varlibdockercontainers
    - hostPath:
        path: /var/log/containers
        type: ''
      name: varlogcontainers
    - hostPath:
        path: /var/log/pods
        type: ''
      name: varlogpods
    - name: kube-api-access-s4rcs
      projected:
        defaultMode: 420
        sources:
          - serviceAccountToken:
              expirationSeconds: 3607
              path: token
          - configMap:
              items:
                - key: ca.crt
                  path: ca.crt
              name: kube-root-ca.crt
          - downwardAPI:
              items:
                - fieldRef:
                    apiVersion: v1
                    fieldPath: metadata.namespace
                  path: namespace
status:
  conditions:
    - lastProbeTime: null
      lastTransitionTime: '2023-04-04T08:33:30Z'
      status: 'True'
      type: Initialized
    - lastProbeTime: null
      lastTransitionTime: '2023-04-04T08:36:44Z'
      message: 'containers with unready status: [filebeat]'
      reason: ContainersNotReady
      status: 'False'
      type: Ready
    - lastProbeTime: null
      lastTransitionTime: '2023-04-04T08:36:44Z'
      message: 'containers with unready status: [filebeat]'
      reason: ContainersNotReady
      status: 'False'
      type: ContainersReady
    - lastProbeTime: null
      lastTransitionTime: '2023-04-04T08:33:30Z'
      status: 'True'
      type: PodScheduled
  containerStatuses:
    - containerID: >-
        containerd://85f2c69219d0a831dab2dba4032c0f61e07917ddb7b8a4919552263bf49f0933
      image: docker.elastic.co/beats/filebeat:8.3.0
      imageID: >-
        docker.elastic.co/beats/filebeat@sha256:2972cf06e669fc62d319bd2135ab7bebb9c476f26ec82934061ba5932a5db5b1
      lastState:
        terminated:
          containerID: >-
            containerd://85f2c69219d0a831dab2dba4032c0f61e07917ddb7b8a4919552263bf49f0933
          exitCode: 1
          finishedAt: '2023-04-04T08:36:43Z'
          reason: Error
          startedAt: '2023-04-04T08:36:42Z'
      name: filebeat
      ready: false
      restartCount: 5
      started: false
      state:
        waiting:
          message: >-
            back-off 2m40s restarting failed container=filebeat
            pod=filebeat-elk-beat-filebeat-ctgx5_logging(50035b3e-c551-4fc7-8a93-f6cb52862a44)
          reason: CrashLoopBackOff
  hostIP: 10.2.0.101
  phase: Running
  podIP: 10.2.0.101
  podIPs:
    - ip: 10.2.0.101
  qosClass: Burstable
  startTime: '2023-04-04T08:33:30Z'

my_custom_policy.te:

module my_custom_policy 1.0;

require {
        type container_var_lib_t;
        type container_t;
        class file { create lock open read rename write };
}

#============= container_t ==============
allow container_t container_var_lib_t:file create;
allow container_t container_var_lib_t:file { open read write rename lock };

[maaft]

Hi! I'm also getting these avc errors when trying to write on volumes provisioned using local-path-provisioner.

type=AVC msg=audit(1680610782.192:1681): avc:  denied  { write } for  pid=9622 comm="barman-cloud-re" name="pvc-1e25420c-f5f8-4929-b1f5-bd1eefc92905_dug-staging_hasura-1" dev="sda3" ino=258 scontext=system_u:system_r:container_t:s0:c715,c838 tcontext=system_u:object_r:usr_t:s0 tclass=dir permissive=0

Any workarounds?

Edit: I think it would be great if local-storage is supported by kube-hetzner from the get-go! It's an important feature to have minimum file-latency e.g. for databases.

[honarkhah]

@honarkhah Good catch, please SSH into your node, and execute that command sudo grep "avc: denied" /var/log/audit/audit.log | audit2allow -M my_custom_policy. Then copy paste here the value of your generated my_custom_policy.te file.

Ideally, before that, apply the generate .pp to double check that it works. If not, re-run the command and apply again the .pp, until you get vault working, and then either open a PR with the content of the .te added to the policy section in locals.tf, or just copy it here so that I add it myself.

Have you guys followed the instructions? I have followed the path and after couple of try and error got the final policy in place and created a PR

[maaft]

ah, sorry - I must have skipped that part. will try

[phinx110]

I use this project to setup cheaper dev/test/staging kubernetes clusters. After reinstalling an older cluster I got the following problems:

• fluent-bit (needs access to local files on the node):

[error] [sqldb] cannot open database /var/log/flb_kube.db [error] [input:tail:tail.0] could not open/create database [error] failed initialize input tail.0 [error] [engine] input initialization failed [error] [lib] backend failed

• openvpn(needs to load "tun" and "conntrack" kernel modules):

Error: Could not process rule: No such file or directory add rule ip filter INPUT iifname tun0 ct state related,established accept ^^^^^^^^

ERROR: Cannot open TUN/TAP dev /dev/net/tun: No such device (errno=19) (((Even though I did mknod /dev/net/tun c 10 200 )))

• lbnodeagent (don't know what it needs):

{"caller":"panic.go:884","msg":"done","op":"shutdown"} panic: runtime error: invalid memory address or nil pointer dereference [signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x1358ad9] goroutine 1 [running]: purelb.io/internal/local.(announcer).announceRemote(0xc000200420, 0xc0007b8d60, 0xc0006a4ad0, 0xc00042b420?, {0xc00042b420, 0x10, 0x10}) /usr/src/internal/local/announcer_local.go:273 +0x519 purelb.io/internal/local.(announcer).SetBalancer(0xc000200420, 0xc0007b8d60, 0x16c9ff1?) /usr/src/internal/local/announcer_local.go:193 +0x5cf main.(controller).ServiceChanged(0xc000204190, 0xc0007b8d60, 0xc000492501?) /usr/src/cmd/lbnodeagent/controller.go:102 +0x9e3 purelb.io/internal/k8s.(Client).sync(0xc0000bc9a0, {0x14312e0?, 0xc0004925e0?}) /usr/src/internal/k8s/k8s.go:403 +0x3bd purelb.io/internal/k8s.(*Client).Run(0xc0000bc9a0, 0xc0001140c0) /usr/src/internal/k8s/k8s.go:280 +0x2be main.main() /usr/src/cmd/lbnodeagent/main.go:119 +0xf2b Stream closed EOF for purelb/lbnodeagent-dlr82 (lbnodeagent) `

These issues have been solved by disabling Selinux. Probably not the smartest Idea but I don't mind to do it on a throwaway clusters. This is how I did it:

ssh root@x.x.x.x setenforce Permissive #This disabeles it until the next restart vi /etc/sysconfig/selinux-policy #set SELINUX=permissive and save, this will persist the setting after node reboot.

From this use case of mine I can conclude that it is probably best to have the Selinux settings be exposed in the kube.tf.example similar to how extra_firewall_rules are. Preferably with documentation on how to configure it like with the Examples section in the readme.md This is necessary because different users have different needs and it's not possible to cover everything in locals.tf

[maaft]

okay, for local-storage this seems to do the trick for me:

nevermind, some permissions are missing. back to the drawing board

module my_custom_policy 1.0;

require {
    type usr_t;
    type container_t;
    class dir { add_name create remove_name setattr write };
    class file { append create rename setattr unlink write };
}

#============= container_t ==============

allow container_t usr_t:dir { add_name create remove_name setattr write };
allow container_t usr_t:file { append create rename setattr unlink write };

I suspect though, that this is highly workload dependent!

@mysticaltech basically, we need to allow every kind of file-/folder-access to support any workloads that make use of local-storage. So any suggestions whats missing in above .te file?

[mysticaltech]

@honarkhah Good job, will merge later on tonight.

@maaft Test it via applying th generated .pp file, if works great, if not, re-run the command for it to post the latest errors. Normally, it will convert all uses cases, so if the above is your final .te that is proven to work, I will integrate it.

@michailkorenev Perfect, .te noted, will integrate, also make sure to test with .pp as described above.

@phinx110 Please grab your .te, test your .pp, if all good post your .te, don't worry no need to disable SELinux I need your help to make this project compatible with SELinux while being has secure as possible, just generate and share your .te file please, will merge later tonight.

[mysticaltech]

@honarkhah Good job, will merge later on tonight.

@maaft Test it via applying the generated .pp file, if works great, if not, re-run the command for it to post the latest errors. Normally, it will convert all uses cases, so if the above is your final .te that is proven to work, I will integrate it.

@michailkorenev Perfect, .te noted, will integrate, also make sure to test with .pp as described above.

@phinx110 Please grab your .te, test your .pp, if all good post your .te, don't worry no need to disable selinux.

[maaft]

@mysticaltech its a very time-consuming process:

• my postgres db does init from backup (takes time)
• after that, new errors occur
• generate and re-apply .pp, throw away old DB, restart restore procedure, wait ...
• i have multiple agents where the pods need to run due to HA-postgres-cluster (different /var/log/audit/audit.log content , therefore different .pp patches - how to aggregate easily?)
• when the cluster finally runs - how can I be sure that everything is included? maybe at the next backup there is still some permission missing? or at any other random time when the cluster does something specific which it hasn't done in my tests?

What I want to say is, wouldn't it be easier to allow just everything regarding files and folders? If yes, where to find such a list?

[mysticaltech]

@maaft No worries than, I will include a quick flag "enable_selinux" to turn off selinux at the k3s level, how it was before. It has always been active at the OS level, but not the k3s level.

[mysticaltech]

Now for best security, you would leave it active, and after you run your cluster, issue the above command to pickup the denied stuff, submit a PR and voila.

[mysticaltech]

@maaft My theory is that applications actually are not that different. Probably the new updated policy with the values above, will fix most issues, and after a few iterations, we will have convered the whole playing field.

So my advice, both @maaft and @phinx110 see the command above, generate your te and pp file, test pp, if good and everything works, submit your final .te content here that is just text. That way we will really map all possible use cases, there aren't so many.

[honarkhah]

@mysticaltech I can help if there is WIP or a list of features that need to develop!

[mysticaltech]

Thanks @honarkhah, really appreciate it!

[mysticaltech]

@maaft @phinx110 @michailkorenev Along with the recently merged SELinux rules additions by @honarkhah, I have merged your respective rules provided above. Please give v2.0.4 a shot, you do not need to create the snapshot, but you do not need to update the module and at least create new nodepools (while taking bringing the count to the old nodepools to 0 after draining the old nodes), or if you prefer completely recreate the cluster.

If that works, great! If not, please let's iterate a little bit, either you add your rules to locals.tf directly via a PR, or you create a discussion about additional SELinux rules and add them there tagging me explicitly so that I add them ASAP.

I believe we are near to mapping all the possible use cases, I also proactively added permissions based on GPT-4 recommendations of common uses cases.

If that approach works, great! If however in the future we see the need for custom rules, we will provide a variable for you to add it, and if necessary, we will provide the ability to turn off SELinux at the k3s level (not the OS level), hopefully that will not be necessary so that clusters deployed with this tool stay as secure as possible.

Again to create your needed policy if you see denied errors:

• SSH in the affected node.
• Run: sudo grep "denied" /var/log/audit/audit.log | audit2allow -M my_custom_policy
• Apply with semodule -i my_custom_policy.pp
• Test, and if failed again, re-rerun the above two commands to catch the remaining denied errors.
• When success, submit the content of your my_custom_policy.te in a discussion tagging me.

[phinx110]

@mysticaltech When testing lbnodeagent I got the following but I'm not sure if this is actually doing anything because it was the first one I tested. It's possible that something else is causing this and not lbnodeagent so I wouldn't include this in the locals.tf just yet:

purelb-lbnodeagent 1.0;

require {
    type init_t;
    type container_t;
    class file { open read };
}

#============= container_t ==============
allow container_t init_t:file { open read };

I need this to load the "tun" (openvpn) and "conntrack" (nftables) kernel modules:

module kernel_module_request 1.0;

require {
    type container_t;
    type kernel_t;
    class system module_request;
}

#============= container_t ==============

#!!!! This avc can be allowed using the boolean 'domain_kernel_load_modules'
allow container_t kernel_t:system module_request;

Regarding the fluentbit-cluster-monitoring it was a mess. I got the following 3 configs:

module fluentbit-cluster-monitoring 1.0;

require {
    type container_log_t;
    type container_t;
    type var_log_t;
    class file { create lock open read setattr watch write };
    class dir { add_name read write };
    class lnk_file read;
}

#============= container_t ==============
allow container_t container_log_t:dir read;
allow container_t container_log_t:file { open read watch };
allow container_t container_log_t:lnk_file read;
allow container_t var_log_t:dir { add_name write };
allow container_t var_log_t:file { create lock open read setattr write };

module fluentbit-cluster-monitoring2 1.0;

require {
    type var_log_t;
    type container_t;
    class dir remove_name;
    class file unlink;
}

#============= container_t ==============
allow container_t var_log_t:dir remove_name;
allow container_t var_log_t:file unlink;

module filesystem_associate 1.0;

require {
    type proc_t;
    type container_t;
    class filesystem associate;
}

#============= container_t ==============
allow container_t proc_t:filesystem associate;

After loading all these modules with semodule -i, the fluentbit still keeps crashing duo to permission problems. If I disable selinux it works again however, grep "denied" /var/log/audit/audit.log | audit2allow does not return to me anything new so now I'm stuck.

I understand the desire to have a fully locked down k3s installation however, even with good instructions provided, it still remains a tedious iterative process, especially if you have to do this for multiple individual failing components separately, in order to have the semodules separated as well, like I did, and in the end it still did not end up working for me. With the older version of this project I had a working setup but after a reinstall I suddenly had to spend quite some time to get it working the correct way. In the end I have decided to just give up on this and disable selinux altogether to get on with it because of timepresure. I simply cannot afford to keep working on this any longer then I currently have and I assume there are quite a few other developers who end up in the same position as I am.

The main reason to have "selinux at the k3s level" is if you run your production on Hetzner. In my case we run our production on AWS and use Hetzner as a cheaper environments to run different version/copies of our software for different departments (dev/test/staging). I would strongly consider the ability to disable "selinux at the k3s level" as a valid "feature" that I would like to request.

[mysticaltech]

@phinx110 Thanks for the rules above, I will add them.

To get unstuck, clear the plate, reset the log file truncate -s 0 /var/log/audit/audit.log and observe it. Also search journalctl for errors. It will show up, either denied or failed, try many times to restart pods / deployments, kill them. Have it trigger the deny error while you observe.

Also, maybe it is already convered by the previous rules above, so let's see.

I will push them ASAP.

[mysticaltech]

@maaft @phinx110 Your new rules have been integrated in v2.0.5, please upgrade with terraform init -upgrade and try again.

@phinx110 Your are close to your goal, try if everything runs well please and if not, find that missing rule as explain above, and please tag me again for me to add it.

If you want to contribute the feature to disable selinux for k3s, just search "selinux:" in the project and you will understand, all we need is a new Boolean variable for it. But again, let's keep that as a last option, basically if it works with SELinux disabled, it will work with SELinux enabled with the right policy, up to you to determine that policy.

[dstockhammer]

Hi @mysticaltech, sorry to resurrect this issue, but I'm having trouble following the debug instructions. I have the same permission errors as described in #739 when running the node exporter integration of Grafana Agent:

grafana-agent caller=collector.go:185 level=error component=integrations integration=node_exporter instance=xx:8080 msg="collector failed" name=filesystem err="open /host/proc/1/mounts: permission denied"
grafana-agent caller=collector.go:185 level=error component=integrations integration=node_exporter instance=xx:8080 msg="collector failed" name=processes err="unable to retrieve number of allocated threads: error reading stat for pid 1: open /host/proc/1/stat: permission denied"

When I ssh into the node I can't find anything related in the audit.log:

grep "avc:  denied" /var/log/audit/audit.log
grep denied /var/log/audit/audit.log
grep avc /var/log/audit/audit.log
grep proc /var/log/audit/audit.log
grep stat /var/log/audit/audit.log
grep mount /var/log/audit/audit.log
grep permission /var/log/audit/audit.log
grep filesystem /var/log/audit/audit.log
grep process /var/log/audit/audit.log

No matches found. Does that mean that the error isn't actually related to SELinux...? What else could I investigate?

Thanks!

[mysticaltech]

@dstockhammer Use an audit.log analyzer, liked audit2why and audit2allow to gen the missing rules and paste them here.

[dstockhammer]

Ok it looks like SELinux has nothing to do with this; apologies for resurrecting the wrong issue in that case. I'll ask OP in the referenced issue.

~ # audit2why < /var/log/audit/audit.log
Nothing to do

~ # audit2why -a
<no matches>

[aleksasiriski]

@mysticaltech Found new ones for minio:

module my_custom_policy 1.0;

require {
    type container_t;
    type io_uring_t;
    class io_uring sqpoll;
    class anon_inode create;
}

#============= container_t ==============
allow container_t io_uring_t:anon_inode create;
allow container_t self:io_uring sqpoll;

[mysticaltech]

@aleksasiriski Perfect, will add it tonight 🙏

[mysticaltech]

@aleksasiriski I actually forgot to add the previous one, so will do now. Could be minio indeed.

[mysticaltech]

@aleksasiriski Added in v2.12.2 🚀

[jhass]

@mysticaltech

I tried running k8s-csi-s3 with the default geesefs backend and it would fail to start it. audit2allow -a -M geesefs generated:

module geesefs 1.0;

require {
    type container_t;
    type fuse_device_t;
    type init_t;
    type container_file_t;
    type http_port_t;
    type io_uring_t;
    class file { execute execute_no_trans };
    class tcp_socket name_connect;
    class chr_file { open read write };
    class io_uring sqpoll;
    class anon_inode { create map read write };
}

#============= container_t ==============
allow container_t io_uring_t:anon_inode { create map read write };
allow container_t self:io_uring sqpoll;

#============= init_t ==============
allow init_t container_file_t:file { execute execute_no_trans };
allow init_t fuse_device_t:chr_file { open read write };

#!!!! This avc can be allowed using the boolean 'nis_enabled'
allow init_t http_port_t:tcp_socket name_connect;

(works with the generated module applied)

Do you want to keep adding rules like this or should there be some way to insert custom ones? 🤔

[mysticaltech]

@jhass Thanks for reporting this. Just added the missing rules in v2.13.2 🚀

[rlj-daf]

I have a similar issue with the Promtail helm chart from Grafana:

i get "... permission denied" errors from the pods. If i deactivate SELinux on a node, the pod will work as expected on this specific node.

I have tried to generate a custom policy with: grep "avc: denied" /var/log/audit/audit.log | audit2allow -M my_custom_policy installed the policy with semodule -i my_custom_policy.pp

I have tested if i worked, by rerunning the pod. If not i reran the two commands. The my_custom_policy.te file changed at first and so did the errors i the pod

but after a couple of reruns of the two commands and rerun of the pod, i end up with the same content in my_custom_policy.te file everytime

i consistently get this error from the promtail pod: ... error writing positions file" error="lstat /run/promtail/positions.yaml: permission denied"

Any ideas on what else to try? 🤞

[mysticaltech]

@rlj-daf share the contents of your policy with me to have a look.

[rlj-daf]

@mysticaltech sorry for the late response

the my_custom_policy.te file:

` module my_custom_policy 1.0;

require { type cert_t; type container_var_run_t; type container_log_t; type container_t; class dir { add_name read remove_name write }; class file { create open read rename unlink write }; class lnk_file read; }

============= container_t ==============

!!!! This avc is allowed in the current policy

allow container_t cert_t:lnk_file read;

!!!! This avc is allowed in the current policy

allow container_t container_log_t:dir read;

!!!! This avc is allowed in the current policy

allow container_t container_var_run_t:dir { add_name remove_name write };

!!!! This avc is allowed in the current policy

allow container_t container_var_run_t:file { create open read rename unlink write }; `

The helm chart i'm using is: repo: https://grafana.github.io/helm-charts chart: promtail version: 6.15.5

[mysticaltech]

@rlj-daf Added to v2.13.3, enjoy!

@jhass Also added a fix, it wasn't done well last time.

[jhass]

@mysticaltech thanks! Actually one question, what's the intended upgrade path here? Since the policy is part of the cloud-init template it applies only to new nodes as far as I can tell.

[mysticaltech]

@jhass Absolutely right. Please try to re-run cloud-init on a per node basis and let me know:

sudo cloud-init init sudo cloud-init modules --mode config sudo cloud-init modules --mode final

Also check:

cat /var/log/cloud-init.log

[jhass]

@mysticaltech It doesn't look to me like it's really doing anything.

cloud-init rerun

$ rm /var/log/cloud-init.log
$  cloud-init init
Cloud-init v. 23.3-8.1 running 'init' at Wed, 13 Mar 2024 18:48:56 +0000. Up 1817.53 seconds.
ci-info: ++++++++++++++++++++++++++++++++++++++++Net device info++++++++++++++++++++++++++++++++++++++++
ci-info: +--------+------+------------------------------+-----------------+--------+-------------------+
ci-info: | Device |  Up  |           Address            |       Mask      | Scope  |     Hw-Address    |
ci-info: +--------+------+------------------------------+-----------------+--------+-------------------+
ci-info: | enp7s0 | True |         10.255.0.101         | 255.255.255.255 | global | 86:00:00:7c:0b:10 |
ci-info: | enp7s0 | True | fe80::25e3:8f99:36e6:9194/64 |        .        |  link  | 86:00:00:7c:0b:10 |
ci-info: |  eth0  | True |         49.13.2.161          | 255.255.255.255 | global | 96:00:03:13:96:b0 |
ci-info: |  eth0  | True | fe80::9dfd:2b8f:1fa9:2aa9/64 |        .        |  link  | 96:00:03:13:96:b0 |
ci-info: |   lo   | True |          127.0.0.1           |    255.0.0.0    |  host  |         .         |
ci-info: |   lo   | True |           ::1/128            |        .        |  host  |         .         |
ci-info: +--------+------+------------------------------+-----------------+--------+-------------------+
ci-info: +++++++++++++++++++++++++++++Route IPv4 info++++++++++++++++++++++++++++++
ci-info: +-------+-------------+------------+-----------------+-----------+-------+
ci-info: | Route | Destination |  Gateway   |     Genmask     | Interface | Flags |
ci-info: +-------+-------------+------------+-----------------+-----------+-------+
ci-info: |   0   |   0.0.0.0   | 172.31.1.1 |     0.0.0.0     |    eth0   |   UG  |
ci-info: |   1   |   10.0.0.0  |  10.0.0.1  |    255.0.0.0    |   enp7s0  |   UG  |
ci-info: |   2   |   10.0.0.1  |  0.0.0.0   | 255.255.255.255 |   enp7s0  |   UH  |
ci-info: |   3   |  172.31.1.1 |  0.0.0.0   | 255.255.255.255 |    eth0   |   UH  |
ci-info: +-------+-------------+------------+-----------------+-----------+-------+
ci-info: +++++++++++++++++++Route IPv6 info+++++++++++++++++++
ci-info: +-------+-------------+---------+-----------+-------+
ci-info: | Route | Destination | Gateway | Interface | Flags |
ci-info: +-------+-------------+---------+-----------+-------+
ci-info: |   0   |  fe80::/64  |    ::   |   enp7s0  |   U   |
ci-info: |   1   |  fe80::/64  |    ::   |    eth0   |   U   |
ci-info: |   3   |    local    |    ::   |   enp7s0  |   U   |
ci-info: |   4   |    local    |    ::   |    eth0   |   U   |
ci-info: |   5   |  multicast  |    ::   |   enp7s0  |   U   |
ci-info: |   6   |  multicast  |    ::   |    eth0   |   U   |
ci-info: +-------+-------------+---------+-----------+-------+
$ cloud-init modules --mode config
Cloud-init v. 23.3-8.1 running 'modules:config' at Wed, 13 Mar 2024 18:49:28 +0000. Up 1849.66 seconds.
$ cloud-init modules --mode final
Cloud-init v. 23.3-8.1 running 'modules:final' at Wed, 13 Mar 2024 18:49:35 +0000. Up 1856.29 seconds.
Cloud-init v. 23.3-8.1 finished at Wed, 13 Mar 2024 18:49:35 +0000. Datasource DataSourceHetzner.  Up 1856.38 seconds
$ cat /var/log/cloud-init.log
2024-03-13 18:48:56,409 - util.py[DEBUG]: Cloud-init v. 23.3-8.1 running 'init' at Wed, 13 Mar 2024 18:48:56 +0000. Up 1817.53 seconds.
2024-03-13 18:48:56,409 - main.py[DEBUG]: No kernel command line url found.
2024-03-13 18:48:56,409 - main.py[DEBUG]: Closing stdin.
2024-03-13 18:48:56,415 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud (recursive=False)
2024-03-13 18:48:56,421 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/scripts (recursive=False)
2024-03-13 18:48:56,423 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/scripts/per-instance (recursive=False)
2024-03-13 18:48:56,425 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/scripts/per-once (recursive=False)
2024-03-13 18:48:56,426 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/scripts/per-boot (recursive=False)
2024-03-13 18:48:56,427 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/scripts/vendor (recursive=False)
2024-03-13 18:48:56,428 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/seed (recursive=False)
2024-03-13 18:48:56,429 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances (recursive=False)
2024-03-13 18:48:56,429 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/handlers (recursive=False)
2024-03-13 18:48:56,430 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/sem (recursive=False)
2024-03-13 18:48:56,431 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data (recursive=False)
2024-03-13 18:48:56,431 - util.py[DEBUG]: Restoring selinux mode for /run/cloud-init/sem (recursive=False)
2024-03-13 18:48:56,432 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [640] 0 bytes
2024-03-13 18:48:56,433 - util.py[DEBUG]: Restoring selinux mode for /var/log/cloud-init.log (recursive=False)
2024-03-13 18:48:56,435 - util.py[DEBUG]: Restoring selinux mode for /var/log/cloud-init.log (recursive=False)
2024-03-13 18:48:56,436 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 0:0
2024-03-13 18:48:56,436 - subp.py[DEBUG]: Running command ['ip', '--json', 'addr'] with allowed return codes [0] (shell=False, capture=True)
2024-03-13 18:48:56,439 - subp.py[DEBUG]: Running command ['ip', '-o', 'route', 'list'] with allowed return codes [0] (shell=False, capture=True)
2024-03-13 18:48:56,441 - subp.py[DEBUG]: Running command ['ip', '--oneline', '-6', 'route', 'list', 'table', 'all'] with allowed return codes [0, 1] (shell=False, capture=True)
2024-03-13 18:48:56,443 - handlers.py[DEBUG]: start: init-network/check-cache: attempting to read from cache [trust]
2024-03-13 18:48:56,443 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
2024-03-13 18:48:56,443 - util.py[DEBUG]: Read 38374 bytes from /var/lib/cloud/instance/obj.pkl
2024-03-13 18:48:56,448 - util.py[DEBUG]: Reading from /run/cloud-init/.instance-id (quiet=False)
2024-03-13 18:48:56,448 - util.py[DEBUG]: Read 9 bytes from /run/cloud-init/.instance-id
2024-03-13 18:48:56,448 - stages.py[DEBUG]: restored from cache with run check: DataSourceHetzner
2024-03-13 18:48:56,449 - handlers.py[DEBUG]: finish: init-network/check-cache: SUCCESS: restored from cache with run check: DataSourceHetzner
2024-03-13 18:48:56,449 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2024-03-13 18:48:56,449 - util.py[DEBUG]: Read 1088 bytes from /etc/cloud/cloud.cfg
2024-03-13 18:48:56,449 - util.py[DEBUG]: Attempting to load yaml from string of length 1088 with allowed root types (,)
2024-03-13 18:48:56,454 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2024-03-13 18:48:56,454 - util.py[DEBUG]: Read 2070 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2024-03-13 18:48:56,454 - util.py[DEBUG]: Attempting to load yaml from string of length 2070 with allowed root types (,)
2024-03-13 18:48:56,456 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2024-03-13 18:48:56,456 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg
2024-03-13 18:48:56,456 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (,)
2024-03-13 18:48:56,456 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,)
2024-03-13 18:48:56,456 - util.py[DEBUG]: loaded blob returned None, returning default.
2024-03-13 18:48:56,457 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
2024-03-13 18:48:56,457 - util.py[DEBUG]: Read 8401 bytes from /var/lib/cloud/instance/cloud-config.txt
2024-03-13 18:48:56,457 - util.py[DEBUG]: Attempting to load yaml from string of length 8401 with allowed root types (,)
2024-03-13 18:48:56,465 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/vendor-cloud-config.txt (quiet=False)
2024-03-13 18:48:56,466 - util.py[DEBUG]: Read 4452 bytes from /var/lib/cloud/instance/vendor-cloud-config.txt
2024-03-13 18:48:56,466 - util.py[DEBUG]: Attempting to load yaml from string of length 4452 with allowed root types (,)
2024-03-13 18:48:56,469 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
2024-03-13 18:48:56,469 - util.py[DEBUG]: Creating symbolic link from '/var/lib/cloud/instance' => '/var/lib/cloud/instances/44169089'
2024-03-13 18:48:56,470 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/handlers (recursive=False)
2024-03-13 18:48:56,471 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/scripts (recursive=False)
2024-03-13 18:48:56,472 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/sem (recursive=False)
2024-03-13 18:48:56,473 - util.py[DEBUG]: Reading from /var/lib/cloud/instances/44169089/datasource (quiet=False)
2024-03-13 18:48:56,473 - util.py[DEBUG]: Read 37 bytes from /var/lib/cloud/instances/44169089/datasource
2024-03-13 18:48:56,473 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/44169089/datasource - wb: [644] 37 bytes
2024-03-13 18:48:56,474 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/datasource (recursive=False)
2024-03-13 18:48:56,476 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/datasource (recursive=False)
2024-03-13 18:48:56,476 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-datasource - wb: [644] 37 bytes
2024-03-13 18:48:56,477 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/previous-datasource (recursive=False)
2024-03-13 18:48:56,478 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/previous-datasource (recursive=False)
2024-03-13 18:48:56,479 - util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False)
2024-03-13 18:48:56,479 - util.py[DEBUG]: Read 9 bytes from /var/lib/cloud/data/instance-id
2024-03-13 18:48:56,479 - stages.py[DEBUG]: previous iid found to be 44169089
2024-03-13 18:48:56,479 - util.py[DEBUG]: Writing to /var/lib/cloud/data/instance-id - wb: [644] 9 bytes
2024-03-13 18:48:56,480 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/instance-id (recursive=False)
2024-03-13 18:48:56,481 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/instance-id (recursive=False)
2024-03-13 18:48:56,482 - util.py[DEBUG]: Writing to /run/cloud-init/.instance-id - wb: [644] 9 bytes
2024-03-13 18:48:56,482 - util.py[DEBUG]: Restoring selinux mode for /run/cloud-init/.instance-id (recursive=False)
2024-03-13 18:48:56,483 - util.py[DEBUG]: Restoring selinux mode for /run/cloud-init/.instance-id (recursive=False)
2024-03-13 18:48:56,483 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-instance-id - wb: [644] 9 bytes
2024-03-13 18:48:56,484 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/previous-instance-id (recursive=False)
2024-03-13 18:48:56,485 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/previous-instance-id (recursive=False)
2024-03-13 18:48:56,486 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 38374 bytes
2024-03-13 18:48:56,487 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/obj.pkl (recursive=False)
2024-03-13 18:48:56,489 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/obj.pkl (recursive=False)
2024-03-13 18:48:56,489 - main.py[DEBUG]: [net] init will now be targeting instance id: 44169089. new=False
2024-03-13 18:48:56,489 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2024-03-13 18:48:56,489 - util.py[DEBUG]: Read 1088 bytes from /etc/cloud/cloud.cfg
2024-03-13 18:48:56,489 - util.py[DEBUG]: Attempting to load yaml from string of length 1088 with allowed root types (,)
2024-03-13 18:48:56,492 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2024-03-13 18:48:56,492 - util.py[DEBUG]: Read 2070 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2024-03-13 18:48:56,492 - util.py[DEBUG]: Attempting to load yaml from string of length 2070 with allowed root types (,)
2024-03-13 18:48:56,494 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2024-03-13 18:48:56,494 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg
2024-03-13 18:48:56,494 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (,)
2024-03-13 18:48:56,494 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,)
2024-03-13 18:48:56,494 - util.py[DEBUG]: loaded blob returned None, returning default.
2024-03-13 18:48:56,494 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
2024-03-13 18:48:56,494 - util.py[DEBUG]: Read 8401 bytes from /var/lib/cloud/instance/cloud-config.txt
2024-03-13 18:48:56,494 - util.py[DEBUG]: Attempting to load yaml from string of length 8401 with allowed root types (,)
2024-03-13 18:48:56,503 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/vendor-cloud-config.txt (quiet=False)
2024-03-13 18:48:56,503 - util.py[DEBUG]: Read 4452 bytes from /var/lib/cloud/instance/vendor-cloud-config.txt
2024-03-13 18:48:56,503 - util.py[DEBUG]: Attempting to load yaml from string of length 4452 with allowed root types (,)
2024-03-13 18:48:56,507 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False)
2024-03-13 18:48:56,507 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/eth0/address
2024-03-13 18:48:56,507 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False)
2024-03-13 18:48:56,507 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address
2024-03-13 18:48:56,507 - util.py[DEBUG]: Reading from /sys/class/net/enp7s0/address (quiet=False)
2024-03-13 18:48:56,507 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/enp7s0/address
2024-03-13 18:48:56,508 - stages.py[DEBUG]: Allowed events: {: {}}
2024-03-13 18:48:56,508 - stages.py[DEBUG]: Event Denied: scopes=['network'] EventType=boot
2024-03-13 18:48:56,508 - stages.py[DEBUG]: Allowed events: {: {}}
2024-03-13 18:48:56,508 - stages.py[DEBUG]: Event Denied: scopes=['network'] EventType=boot-legacy
2024-03-13 18:48:56,508 - stages.py[DEBUG]: No network config applied. Neither a new instance nor datasource network update allowed
2024-03-13 18:48:56,508 - stages.py[DEBUG]: applying net config names for {'config': [{'mac_address': '96:00:03:13:96:b0', 'name': 'eth0', 'subnets': [{'ipv4': True, 'type': 'dhcp'}, {'address': '2a01:4f8:c012:8de1::1/64', 'dns_nameservers': ['2a01:4ff:ff00::add:2', '2a01:4ff:ff00::add:1'], 'gateway': 'fe80::1', 'ipv6': True, 'type': 'static'}], 'type': 'physical'}], 'version': 1}
2024-03-13 18:48:56,508 - stages.py[DEBUG]: Using distro class 
2024-03-13 18:48:56,509 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False)
2024-03-13 18:48:56,509 - util.py[DEBUG]: Read 7 bytes from /sys/class/net/eth0/device/device
2024-03-13 18:48:56,509 - util.py[DEBUG]: Reading from /sys/class/net/eth0/addr_assign_type (quiet=False)
2024-03-13 18:48:56,509 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/eth0/addr_assign_type
2024-03-13 18:48:56,509 - util.py[DEBUG]: Reading from /sys/class/net/eth0/uevent (quiet=False)
2024-03-13 18:48:56,509 - util.py[DEBUG]: Read 25 bytes from /sys/class/net/eth0/uevent
2024-03-13 18:48:56,509 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False)
2024-03-13 18:48:56,509 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/eth0/address
2024-03-13 18:48:56,509 - __init__.py[DEBUG]: ovs-vsctl not in PATH; not detecting Open vSwitch interfaces
2024-03-13 18:48:56,509 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False)
2024-03-13 18:48:56,509 - util.py[DEBUG]: Read 7 bytes from /sys/class/net/eth0/device/device
2024-03-13 18:48:56,509 - util.py[DEBUG]: Reading from /sys/class/net/lo/addr_assign_type (quiet=False)
2024-03-13 18:48:56,509 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/lo/addr_assign_type
2024-03-13 18:48:56,509 - util.py[DEBUG]: Reading from /sys/class/net/lo/uevent (quiet=False)
2024-03-13 18:48:56,509 - util.py[DEBUG]: Read 23 bytes from /sys/class/net/lo/uevent
2024-03-13 18:48:56,509 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False)
2024-03-13 18:48:56,510 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address
2024-03-13 18:48:56,510 - util.py[DEBUG]: Reading from /sys/class/net/lo/device/device (quiet=False)
2024-03-13 18:48:56,510 - util.py[DEBUG]: Reading from /sys/class/net/enp7s0/addr_assign_type (quiet=False)
2024-03-13 18:48:56,510 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/enp7s0/addr_assign_type
2024-03-13 18:48:56,510 - util.py[DEBUG]: Reading from /sys/class/net/enp7s0/uevent (quiet=False)
2024-03-13 18:48:56,510 - util.py[DEBUG]: Read 27 bytes from /sys/class/net/enp7s0/uevent
2024-03-13 18:48:56,510 - util.py[DEBUG]: Reading from /sys/class/net/enp7s0/address (quiet=False)
2024-03-13 18:48:56,510 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/enp7s0/address
2024-03-13 18:48:56,510 - util.py[DEBUG]: Reading from /sys/class/net/enp7s0/device/device (quiet=False)
2024-03-13 18:48:56,510 - util.py[DEBUG]: Read 7 bytes from /sys/class/net/enp7s0/device/device
2024-03-13 18:48:56,510 - util.py[DEBUG]: Reading from /sys/class/net/eth0/operstate (quiet=False)
2024-03-13 18:48:56,510 - util.py[DEBUG]: Read 3 bytes from /sys/class/net/eth0/operstate
2024-03-13 18:48:56,510 - util.py[DEBUG]: Reading from /sys/class/net/lo/operstate (quiet=False)
2024-03-13 18:48:56,510 - util.py[DEBUG]: Read 8 bytes from /sys/class/net/lo/operstate
2024-03-13 18:48:56,510 - util.py[DEBUG]: Reading from /sys/class/net/enp7s0/operstate (quiet=False)
2024-03-13 18:48:56,510 - util.py[DEBUG]: Read 3 bytes from /sys/class/net/enp7s0/operstate
2024-03-13 18:48:56,510 - subp.py[DEBUG]: Running command ['ip', '-6', 'addr', 'show', 'permanent', 'scope', 'global'] with allowed return codes [0] (shell=False, capture=True)
2024-03-13 18:48:56,513 - subp.py[DEBUG]: Running command ['ip', '-4', 'addr', 'show'] with allowed return codes [0] (shell=False, capture=True)
2024-03-13 18:48:56,515 - __init__.py[DEBUG]: Detected interfaces {'eth0': {'downable': False, 'device_id': '0x0001', 'driver': 'virtio_net', 'mac': '96:00:03:13:96:b0', 'name': 'eth0', 'up': True}, 'lo': {'downable': False, 'device_id': None, 'driver': None, 'mac': '00:00:00:00:00:00', 'name': 'lo', 'up': True}, 'enp7s0': {'downable': False, 'device_id': '0x0001', 'driver': 'virtio_net', 'mac': '86:00:00:7c:0b:10', 'name': 'enp7s0', 'up': True}}
2024-03-13 18:48:56,515 - __init__.py[DEBUG]: no work necessary for renaming of [['96:00:03:13:96:b0', 'eth0', 'virtio_net', '0x0001']]
2024-03-13 18:48:56,515 - handlers.py[DEBUG]: start: init-network/setup-datasource: setting up datasource
2024-03-13 18:48:56,515 - handlers.py[DEBUG]: finish: init-network/setup-datasource: SUCCESS: setting up datasource
2024-03-13 18:48:56,516 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/44169089/user-data.txt - wb: [600] 2989 bytes
2024-03-13 18:48:56,517 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/user-data.txt (recursive=False)
2024-03-13 18:48:56,519 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/user-data.txt (recursive=False)
2024-03-13 18:48:56,521 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/44169089/user-data.txt.i - wb: [600] 9067 bytes
2024-03-13 18:48:56,522 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/user-data.txt.i (recursive=False)
2024-03-13 18:48:56,524 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/user-data.txt.i (recursive=False)
2024-03-13 18:48:56,524 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/44169089/vendor-data.txt - wb: [600] 4755 bytes
2024-03-13 18:48:56,526 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/vendor-data.txt (recursive=False)
2024-03-13 18:48:56,527 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/vendor-data.txt (recursive=False)
2024-03-13 18:48:56,528 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/44169089/vendor-data.txt.i - wb: [600] 4777 bytes
2024-03-13 18:48:56,529 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/vendor-data.txt.i (recursive=False)
2024-03-13 18:48:56,531 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/vendor-data.txt.i (recursive=False)
2024-03-13 18:48:56,531 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/44169089/vendor-data2.txt - wb: [600] 0 bytes
2024-03-13 18:48:56,532 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/vendor-data2.txt (recursive=False)
2024-03-13 18:48:56,533 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/vendor-data2.txt (recursive=False)
2024-03-13 18:48:56,534 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/44169089/vendor-data2.txt.i - wb: [600] 308 bytes
2024-03-13 18:48:56,535 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/vendor-data2.txt.i (recursive=False)
2024-03-13 18:48:56,536 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/vendor-data2.txt.i (recursive=False)
2024-03-13 18:48:56,537 - cc_set_hostname.py[DEBUG]: Configuration option 'preserve_hostname' is set, not setting the hostname in module set_hostname
2024-03-13 18:48:56,537 - helpers.py[DEBUG]: consume_data already ran (freq=once-per-instance)
2024-03-13 18:48:56,537 - handlers.py[DEBUG]: start: init-network/consume-user-data: reading and applying user-data
2024-03-13 18:48:56,537 - stages.py[DEBUG]: Added default handler for {'text/cloud-config', 'text/cloud-config-jsonp'} from CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']]
2024-03-13 18:48:56,537 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript'} from ShellScriptPartHandler: [['text/x-shellscript']]
2024-03-13 18:48:56,537 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript-per-boot'} from ShellScriptByFreqPartHandler: [['text/x-shellscript-per-boot']]
2024-03-13 18:48:56,537 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript-per-instance'} from ShellScriptByFreqPartHandler: [['text/x-shellscript-per-instance']]
2024-03-13 18:48:56,537 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript-per-once'} from ShellScriptByFreqPartHandler: [['text/x-shellscript-per-once']]
2024-03-13 18:48:56,538 - stages.py[DEBUG]: Added default handler for {'text/cloud-boothook'} from BootHookPartHandler: [['text/cloud-boothook']]
2024-03-13 18:48:56,538 - stages.py[DEBUG]: Added default handler for {'text/jinja2'} from JinjaTemplatePartHandler: [['text/jinja2']]
2024-03-13 18:48:56,538 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__begin__, None, 3) with frequency always
2024-03-13 18:48:56,538 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__begin__, None, 2) with frequency always
2024-03-13 18:48:56,538 - __init__.py[DEBUG]: Calling handler ShellScriptByFreqPartHandler: [['text/x-shellscript-per-boot']] (__begin__, None, 2) with frequency always
2024-03-13 18:48:56,538 - __init__.py[DEBUG]: Calling handler ShellScriptByFreqPartHandler: [['text/x-shellscript-per-instance']] (__begin__, None, 2) with frequency always
2024-03-13 18:48:56,538 - __init__.py[DEBUG]: Calling handler ShellScriptByFreqPartHandler: [['text/x-shellscript-per-once']] (__begin__, None, 2) with frequency always
2024-03-13 18:48:56,538 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__begin__, None, 2) with frequency always
2024-03-13 18:48:56,538 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__begin__, None, 3) with frequency always
2024-03-13 18:48:56,538 - __init__.py[DEBUG]: {'Content-Disposition': 'attachment; filename="init.cfg"', 'Content-Transfer-Encoding': '7bit', 'Content-Type': 'text/cloud-config', 'Mime-Version': '1.0'}
2024-03-13 18:48:56,538 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (text/cloud-config, init.cfg, 3) with frequency always
2024-03-13 18:48:56,538 - util.py[DEBUG]: Attempting to load yaml from string of length 8730 with allowed root types (,)
2024-03-13 18:48:56,546 - cloud_config.py[DEBUG]: Merging by applying [('dict', ['replace']), ('list', []), ('str', [])]
2024-03-13 18:48:56,546 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__end__, None, 3) with frequency always
2024-03-13 18:48:56,554 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/44169089/cloud-config.txt - wb: [600] 8401 bytes
2024-03-13 18:48:56,556 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/cloud-config.txt (recursive=False)
2024-03-13 18:48:56,557 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/cloud-config.txt (recursive=False)
2024-03-13 18:48:56,558 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__end__, None, 2) with frequency always
2024-03-13 18:48:56,558 - __init__.py[DEBUG]: Calling handler ShellScriptByFreqPartHandler: [['text/x-shellscript-per-boot']] (__end__, None, 2) with frequency always
2024-03-13 18:48:56,558 - __init__.py[DEBUG]: Calling handler ShellScriptByFreqPartHandler: [['text/x-shellscript-per-instance']] (__end__, None, 2) with frequency always
2024-03-13 18:48:56,558 - __init__.py[DEBUG]: Calling handler ShellScriptByFreqPartHandler: [['text/x-shellscript-per-once']] (__end__, None, 2) with frequency always
2024-03-13 18:48:56,558 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__end__, None, 2) with frequency always
2024-03-13 18:48:56,558 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__end__, None, 3) with frequency always
2024-03-13 18:48:56,559 - handlers.py[DEBUG]: finish: init-network/consume-user-data: SUCCESS: reading and applying user-data
2024-03-13 18:48:56,559 - handlers.py[DEBUG]: start: init-network/consume-vendor-data: reading and applying vendor-data
2024-03-13 18:48:56,559 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
2024-03-13 18:48:56,559 - util.py[DEBUG]: Read 8401 bytes from /var/lib/cloud/instance/cloud-config.txt
2024-03-13 18:48:56,559 - util.py[DEBUG]: Attempting to load yaml from string of length 8401 with allowed root types (,)
2024-03-13 18:48:56,568 - stages.py[DEBUG]: vendordata will be consumed. disabled_handlers=None
2024-03-13 18:48:56,568 - stages.py[DEBUG]: Added default handler for {'text/cloud-config', 'text/cloud-config-jsonp'} from CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']]
2024-03-13 18:48:56,568 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript'} from ShellScriptPartHandler: [['text/x-shellscript']]
2024-03-13 18:48:56,568 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript-per-boot'} from ShellScriptByFreqPartHandler: [['text/x-shellscript-per-boot']]
2024-03-13 18:48:56,568 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript-per-instance'} from ShellScriptByFreqPartHandler: [['text/x-shellscript-per-instance']]
2024-03-13 18:48:56,568 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript-per-once'} from ShellScriptByFreqPartHandler: [['text/x-shellscript-per-once']]
2024-03-13 18:48:56,568 - stages.py[DEBUG]: Added default handler for {'text/cloud-boothook'} from BootHookPartHandler: [['text/cloud-boothook']]
2024-03-13 18:48:56,568 - stages.py[DEBUG]: Added default handler for {'text/jinja2'} from JinjaTemplatePartHandler: [['text/jinja2']]
2024-03-13 18:48:56,569 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__begin__, None, 3) with frequency always
2024-03-13 18:48:56,569 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__begin__, None, 2) with frequency always
2024-03-13 18:48:56,569 - __init__.py[DEBUG]: Calling handler ShellScriptByFreqPartHandler: [['text/x-shellscript-per-boot']] (__begin__, None, 2) with frequency always
2024-03-13 18:48:56,569 - __init__.py[DEBUG]: Calling handler ShellScriptByFreqPartHandler: [['text/x-shellscript-per-instance']] (__begin__, None, 2) with frequency always
2024-03-13 18:48:56,569 - __init__.py[DEBUG]: Calling handler ShellScriptByFreqPartHandler: [['text/x-shellscript-per-once']] (__begin__, None, 2) with frequency always
2024-03-13 18:48:56,569 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__begin__, None, 2) with frequency always
2024-03-13 18:48:56,569 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__begin__, None, 3) with frequency always
2024-03-13 18:48:56,569 - __init__.py[DEBUG]: {'Content-Type': 'text/cloud-config; charset="us-ascii"', 'MIME-Version': '1.0', 'Content-Transfer-Encoding': '7bit', 'Content-Disposition': 'attachment; filename="cloud-config"'}
2024-03-13 18:48:56,569 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (text/cloud-config, cloud-config, 3) with frequency always
2024-03-13 18:48:56,569 - util.py[DEBUG]: Attempting to load yaml from string of length 4200 with allowed root types (,)
2024-03-13 18:48:56,571 - cloud_config.py[DEBUG]: Merging by applying [('dict', ['replace']), ('list', []), ('str', [])]
2024-03-13 18:48:56,572 - __init__.py[DEBUG]: {'Content-Type': 'text/cloud-boothook; charset="us-ascii"', 'MIME-Version': '1.0', 'Content-Transfer-Encoding': '7bit', 'Content-Disposition': 'attachment; filename="hc-boot-script"'}
2024-03-13 18:48:56,572 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (text/cloud-boothook, hc-boot-script, 2) with frequency always
2024-03-13 18:48:56,572 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/44169089/boothooks/hc-boot-script - wb: [700] 12 bytes
2024-03-13 18:48:56,573 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/boothooks/hc-boot-script (recursive=False)
2024-03-13 18:48:56,575 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/boothooks/hc-boot-script (recursive=False)
2024-03-13 18:48:56,575 - subp.py[DEBUG]: Running command ['/var/lib/cloud/instances/44169089/boothooks/hc-boot-script'] with allowed return codes [0] (shell=False, capture=True)
2024-03-13 18:48:56,578 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__end__, None, 3) with frequency always
2024-03-13 18:48:56,582 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/44169089/vendor-cloud-config.txt - wb: [600] 4452 bytes
2024-03-13 18:48:56,583 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/vendor-cloud-config.txt (recursive=False)
2024-03-13 18:48:56,585 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/vendor-cloud-config.txt (recursive=False)
2024-03-13 18:48:56,586 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__end__, None, 2) with frequency always
2024-03-13 18:48:56,586 - __init__.py[DEBUG]: Calling handler ShellScriptByFreqPartHandler: [['text/x-shellscript-per-boot']] (__end__, None, 2) with frequency always
2024-03-13 18:48:56,586 - __init__.py[DEBUG]: Calling handler ShellScriptByFreqPartHandler: [['text/x-shellscript-per-instance']] (__end__, None, 2) with frequency always
2024-03-13 18:48:56,586 - __init__.py[DEBUG]: Calling handler ShellScriptByFreqPartHandler: [['text/x-shellscript-per-once']] (__end__, None, 2) with frequency always
2024-03-13 18:48:56,586 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__end__, None, 2) with frequency always
2024-03-13 18:48:56,586 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__end__, None, 3) with frequency always
2024-03-13 18:48:56,586 - handlers.py[DEBUG]: finish: init-network/consume-vendor-data: SUCCESS: reading and applying vendor-data
2024-03-13 18:48:56,586 - handlers.py[DEBUG]: start: init-network/consume-vendor-data2: reading and applying vendor-data2
2024-03-13 18:48:56,586 - stages.py[DEBUG]: no vendordata2 from datasource
2024-03-13 18:48:56,586 - handlers.py[DEBUG]: finish: init-network/consume-vendor-data2: SUCCESS: reading and applying vendor-data2
2024-03-13 18:48:56,586 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2024-03-13 18:48:56,586 - util.py[DEBUG]: Read 1088 bytes from /etc/cloud/cloud.cfg
2024-03-13 18:48:56,587 - util.py[DEBUG]: Attempting to load yaml from string of length 1088 with allowed root types (,)
2024-03-13 18:48:56,589 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2024-03-13 18:48:56,589 - util.py[DEBUG]: Read 2070 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2024-03-13 18:48:56,589 - util.py[DEBUG]: Attempting to load yaml from string of length 2070 with allowed root types (,)
2024-03-13 18:48:56,591 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2024-03-13 18:48:56,591 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg
2024-03-13 18:48:56,591 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (,)
2024-03-13 18:48:56,592 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,)
2024-03-13 18:48:56,592 - util.py[DEBUG]: loaded blob returned None, returning default.
2024-03-13 18:48:56,592 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
2024-03-13 18:48:56,592 - util.py[DEBUG]: Read 8401 bytes from /var/lib/cloud/instance/cloud-config.txt
2024-03-13 18:48:56,592 - util.py[DEBUG]: Attempting to load yaml from string of length 8401 with allowed root types (,)
2024-03-13 18:48:56,601 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/vendor-cloud-config.txt (quiet=False)
2024-03-13 18:48:56,601 - util.py[DEBUG]: Read 4452 bytes from /var/lib/cloud/instance/vendor-cloud-config.txt
2024-03-13 18:48:56,601 - util.py[DEBUG]: Attempting to load yaml from string of length 4452 with allowed root types (,)
2024-03-13 18:48:56,605 - atomic_helper.py[DEBUG]: Atomically writing to file /run/cloud-init/combined-cloud-config.json (via temporary file /run/cloud-init/tmp8alj0ict) - w: [600] 15101 bytes/chars
2024-03-13 18:48:56,605 - util.py[DEBUG]: Reading from /run/cloud-init/instance-data-sensitive.json (quiet=False)
2024-03-13 18:48:56,605 - util.py[DEBUG]: Read 32180 bytes from /run/cloud-init/instance-data-sensitive.json
2024-03-13 18:48:56,606 - atomic_helper.py[DEBUG]: Atomically writing to file /run/cloud-init/instance-data-sensitive.json (via temporary file /run/cloud-init/tmpfp61s3sv) - w: [600] 32180 bytes/chars
2024-03-13 18:48:56,606 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:48:56,606 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:48:56,614 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
2024-03-13 18:48:56,614 - util.py[DEBUG]: Read 8401 bytes from /var/lib/cloud/instance/cloud-config.txt
2024-03-13 18:48:56,614 - util.py[DEBUG]: Attempting to load yaml from string of length 8401 with allowed root types (,)
2024-03-13 18:48:56,623 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/vendor-cloud-config.txt (quiet=False)
2024-03-13 18:48:56,623 - util.py[DEBUG]: Read 4452 bytes from /var/lib/cloud/instance/vendor-cloud-config.txt
2024-03-13 18:48:56,623 - util.py[DEBUG]: Attempting to load yaml from string of length 4452 with allowed root types (,)
2024-03-13 18:48:56,629 - handlers.py[DEBUG]: start: init-network/activate-datasource: activating datasource
2024-03-13 18:48:56,630 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 38374 bytes
2024-03-13 18:48:56,632 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/obj.pkl (recursive=False)
2024-03-13 18:48:56,635 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/obj.pkl (recursive=False)
2024-03-13 18:48:56,636 - handlers.py[DEBUG]: finish: init-network/activate-datasource: SUCCESS: activating datasource
2024-03-13 18:48:56,636 - main.py[DEBUG]: no di_report found in config.
2024-03-13 18:48:56,637 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:48:56,637 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:48:56,639 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:48:56,639 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:48:56,641 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:48:56,641 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:48:56,643 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:48:56,643 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:48:56,645 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:48:56,645 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:48:56,647 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:48:56,647 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:48:56,649 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:48:56,649 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:48:56,651 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:48:56,651 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:48:56,652 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:48:56,652 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:48:56,654 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:48:56,654 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:48:56,656 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:48:56,657 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:48:56,659 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:48:56,659 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:48:56,661 - stages.py[DEBUG]: Using distro class 
2024-03-13 18:48:56,662 - modules.py[INFO]: Skipping modules 'bootcmd,disk_setup,rsyslog' because no applicable config is provided.
2024-03-13 18:48:56,663 - modules.py[DEBUG]: Running module migrator () with frequency always
2024-03-13 18:48:56,663 - handlers.py[DEBUG]: start: init-network/config-migrator: running config-migrator with frequency always
2024-03-13 18:48:56,663 - helpers.py[DEBUG]: Running config-migrator using lock ()
2024-03-13 18:48:56,663 - cc_migrator.py[DEBUG]: Migrated 0 semaphore files to there canonicalized names
2024-03-13 18:48:56,663 - handlers.py[DEBUG]: finish: init-network/config-migrator: SUCCESS: config-migrator ran successfully
2024-03-13 18:48:56,664 - modules.py[DEBUG]: Running module write-files () with frequency once-per-instance
2024-03-13 18:48:56,664 - handlers.py[DEBUG]: start: init-network/config-write-files: running config-write-files with frequency once-per-instance
2024-03-13 18:48:56,664 - helpers.py[DEBUG]: config-write-files already ran (freq=once-per-instance)
2024-03-13 18:48:56,664 - handlers.py[DEBUG]: finish: init-network/config-write-files: SUCCESS: config-write-files previously ran
2024-03-13 18:48:56,664 - modules.py[DEBUG]: Running module growpart () with frequency always
2024-03-13 18:48:56,664 - handlers.py[DEBUG]: start: init-network/config-growpart: running config-growpart with frequency always
2024-03-13 18:48:56,664 - helpers.py[DEBUG]: Running config-growpart using lock ()
2024-03-13 18:48:56,664 - subp.py[DEBUG]: Running command ['growpart', '--help'] with allowed return codes [0] (shell=False, capture=True)
2024-03-13 18:48:56,672 - util.py[DEBUG]: Reading from /proc/1864/mountinfo (quiet=False)
2024-03-13 18:48:56,672 - util.py[DEBUG]: Read 4050 bytes from /proc/1864/mountinfo
2024-03-13 18:48:56,672 - util.py[DEBUG]: Reading from /sys/class/block/sda2/partition (quiet=False)
2024-03-13 18:48:56,672 - util.py[DEBUG]: Read 2 bytes from /sys/class/block/sda2/partition
2024-03-13 18:48:56,672 - util.py[DEBUG]: Reading from /sys/devices/pci0000:00/0000:00:02.5/0000:06:00.0/virtio5/host0/target0:0:0/0:0:0:1/block/sda/dev (quiet=False)
2024-03-13 18:48:56,672 - util.py[DEBUG]: Read 4 bytes from /sys/devices/pci0000:00/0000:00:02.5/0000:06:00.0/virtio5/host0/target0:0:0/0:0:0:1/block/sda/dev
2024-03-13 18:48:56,673 - util.py[DEBUG]: Reading from /proc/1864/mountinfo (quiet=False)
2024-03-13 18:48:56,673 - util.py[DEBUG]: Read 4050 bytes from /proc/1864/mountinfo
2024-03-13 18:48:56,673 - util.py[DEBUG]: Reading from /proc/1864/mountinfo (quiet=False)
2024-03-13 18:48:56,673 - util.py[DEBUG]: Read 4050 bytes from /proc/1864/mountinfo
2024-03-13 18:48:56,674 - subp.py[DEBUG]: Running command ['growpart', '--dry-run', '/dev/sda', '2'] with allowed return codes [0] (shell=False, capture=True)
2024-03-13 18:48:56,722 - util.py[DEBUG]: resize_devices took 0.050 seconds
2024-03-13 18:48:56,722 - cc_growpart.py[DEBUG]: '/var' NOCHANGE: no change necessary (/dev/sda, 2)
2024-03-13 18:48:56,722 - handlers.py[DEBUG]: finish: init-network/config-growpart: SUCCESS: config-growpart ran successfully
2024-03-13 18:48:56,722 - modules.py[DEBUG]: Running module resizefs () with frequency always
2024-03-13 18:48:56,722 - handlers.py[DEBUG]: start: init-network/config-resizefs: running config-resizefs with frequency always
2024-03-13 18:48:56,722 - helpers.py[DEBUG]: Running config-resizefs using lock ()
2024-03-13 18:48:56,722 - util.py[DEBUG]: Reading from /proc/1864/mountinfo (quiet=False)
2024-03-13 18:48:56,723 - util.py[DEBUG]: Read 4050 bytes from /proc/1864/mountinfo
2024-03-13 18:48:56,723 - cc_resizefs.py[DEBUG]: resize_info: dev=/dev/sda2 mnt_point=/ path=/
2024-03-13 18:48:56,723 - util.py[DEBUG]: Reading from /proc/1864/mountinfo (quiet=False)
2024-03-13 18:48:56,723 - util.py[DEBUG]: Read 4050 bytes from /proc/1864/mountinfo
2024-03-13 18:48:56,723 - subp.py[DEBUG]: Running command ['btrfs', '--version'] with allowed return codes [0] (shell=False, capture=True)
2024-03-13 18:48:56,725 - cc_resizefs.py[DEBUG]: Resizing / (btrfs) using btrfs filesystem resize --enqueue max //.snapshots
2024-03-13 18:48:56,725 - subp.py[DEBUG]: Running command ('btrfs', 'filesystem', 'resize', '--enqueue', 'max', '//.snapshots') with allowed return codes [0] (shell=False, capture=True)
2024-03-13 18:48:56,727 - util.py[DEBUG]: Resizing took 0.002 seconds
2024-03-13 18:48:56,727 - cc_resizefs.py[DEBUG]: Resized root filesystem (type=btrfs, val=True)
2024-03-13 18:48:56,727 - handlers.py[DEBUG]: finish: init-network/config-resizefs: SUCCESS: config-resizefs ran successfully
2024-03-13 18:48:56,727 - modules.py[DEBUG]: Running module mounts () with frequency once-per-instance
2024-03-13 18:48:56,727 - handlers.py[DEBUG]: start: init-network/config-mounts: running config-mounts with frequency once-per-instance
2024-03-13 18:48:56,727 - helpers.py[DEBUG]: config-mounts already ran (freq=once-per-instance)
2024-03-13 18:48:56,727 - handlers.py[DEBUG]: finish: init-network/config-mounts: SUCCESS: config-mounts previously ran
2024-03-13 18:48:56,727 - modules.py[DEBUG]: Running module set_hostname () with frequency once-per-instance
2024-03-13 18:48:56,727 - handlers.py[DEBUG]: start: init-network/config-set_hostname: running config-set_hostname with frequency once-per-instance
2024-03-13 18:48:56,728 - helpers.py[DEBUG]: config-set_hostname already ran (freq=once-per-instance)
2024-03-13 18:48:56,728 - handlers.py[DEBUG]: finish: init-network/config-set_hostname: SUCCESS: config-set_hostname previously ran
2024-03-13 18:48:56,728 - modules.py[DEBUG]: Running module update_hostname () with frequency always
2024-03-13 18:48:56,728 - handlers.py[DEBUG]: start: init-network/config-update_hostname: running config-update_hostname with frequency always
2024-03-13 18:48:56,728 - helpers.py[DEBUG]: Running config-update_hostname using lock ()
2024-03-13 18:48:56,728 - cc_update_hostname.py[DEBUG]: Configuration option 'preserve_hostname' is set, not updating the hostname in module update_hostname
2024-03-13 18:48:56,728 - handlers.py[DEBUG]: finish: init-network/config-update_hostname: SUCCESS: config-update_hostname ran successfully
2024-03-13 18:48:56,728 - modules.py[DEBUG]: Running module update_etc_hosts () with frequency always
2024-03-13 18:48:56,728 - handlers.py[DEBUG]: start: init-network/config-update_etc_hosts: running config-update_etc_hosts with frequency always
2024-03-13 18:48:56,728 - helpers.py[DEBUG]: Running config-update_etc_hosts using lock ()
2024-03-13 18:48:56,728 - util.py[DEBUG]: Reading from /etc/cloud/templates/hosts.suse.tmpl (quiet=False)
2024-03-13 18:48:56,728 - util.py[DEBUG]: Read 1067 bytes from /etc/cloud/templates/hosts.suse.tmpl
2024-03-13 18:48:56,728 - templater.py[DEBUG]: Rendering content of '/etc/cloud/templates/hosts.suse.tmpl' using renderer jinja
2024-03-13 18:48:56,732 - util.py[DEBUG]: Writing to /etc/hosts - wb: [644] 911 bytes
2024-03-13 18:48:56,735 - util.py[DEBUG]: Restoring selinux mode for /etc/hosts (recursive=False)
2024-03-13 18:48:56,737 - util.py[DEBUG]: Restoring selinux mode for /etc/hosts (recursive=False)
2024-03-13 18:48:56,737 - handlers.py[DEBUG]: finish: init-network/config-update_etc_hosts: SUCCESS: config-update_etc_hosts ran successfully
2024-03-13 18:48:56,738 - modules.py[DEBUG]: Running module users-groups () with frequency once-per-instance
2024-03-13 18:48:56,738 - handlers.py[DEBUG]: start: init-network/config-users-groups: running config-users-groups with frequency once-per-instance
2024-03-13 18:48:56,738 - helpers.py[DEBUG]: config-users-groups already ran (freq=once-per-instance)
2024-03-13 18:48:56,738 - handlers.py[DEBUG]: finish: init-network/config-users-groups: SUCCESS: config-users-groups previously ran
2024-03-13 18:48:56,738 - modules.py[DEBUG]: Running module ssh () with frequency once-per-instance
2024-03-13 18:48:56,738 - handlers.py[DEBUG]: start: init-network/config-ssh: running config-ssh with frequency once-per-instance
2024-03-13 18:48:56,738 - helpers.py[DEBUG]: config-ssh already ran (freq=once-per-instance)
2024-03-13 18:48:56,738 - handlers.py[DEBUG]: finish: init-network/config-ssh: SUCCESS: config-ssh previously ran
2024-03-13 18:48:56,738 - main.py[DEBUG]: Ran 10 modules with 0 failures
2024-03-13 18:48:56,739 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmps7csl5fa) - w: [644] 597 bytes/chars
2024-03-13 18:48:56,739 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2024-03-13 18:48:56,739 - util.py[DEBUG]: Read 16 bytes from /proc/uptime
2024-03-13 18:48:56,739 - util.py[DEBUG]: cloud-init mode 'init' took 0.440 seconds (0.44)
2024-03-13 18:48:56,739 - handlers.py[DEBUG]: finish: init-network: SUCCESS: searching for network datasources
2024-03-13 18:49:28,570 - util.py[DEBUG]: Cloud-init v. 23.3-8.1 running 'modules:config' at Wed, 13 Mar 2024 18:49:28 +0000. Up 1849.66 seconds.
2024-03-13 18:49:28,571 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:49:28,572 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:49:28,575 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:49:28,575 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:49:28,578 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:49:28,578 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:49:28,580 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:49:28,580 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:49:28,583 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:49:28,583 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:49:28,585 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:49:28,585 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:49:28,586 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:49:28,586 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:49:28,588 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:49:28,588 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:49:28,589 - stages.py[DEBUG]: Using distro class 
2024-03-13 18:49:28,590 - modules.py[INFO]: Skipping modules 'timezone,resolv_conf,ntp,zypper_add_repo,disable-ec2-metadata' because no applicable config is provided.
2024-03-13 18:49:28,590 - modules.py[DEBUG]: Running module locale () with frequency once-per-instance
2024-03-13 18:49:28,591 - handlers.py[DEBUG]: start: modules-config/config-locale: running config-locale with frequency once-per-instance
2024-03-13 18:49:28,591 - helpers.py[DEBUG]: config-locale already ran (freq=once-per-instance)
2024-03-13 18:49:28,591 - handlers.py[DEBUG]: finish: modules-config/config-locale: SUCCESS: config-locale previously ran
2024-03-13 18:49:28,591 - modules.py[DEBUG]: Running module set-passwords () with frequency once-per-instance
2024-03-13 18:49:28,591 - handlers.py[DEBUG]: start: modules-config/config-set-passwords: running config-set-passwords with frequency once-per-instance
2024-03-13 18:49:28,591 - helpers.py[DEBUG]: config-set-passwords already ran (freq=once-per-instance)
2024-03-13 18:49:28,591 - handlers.py[DEBUG]: finish: modules-config/config-set-passwords: SUCCESS: config-set-passwords previously ran
2024-03-13 18:49:28,591 - modules.py[DEBUG]: Running module runcmd () with frequency once-per-instance
2024-03-13 18:49:28,592 - handlers.py[DEBUG]: start: modules-config/config-runcmd: running config-runcmd with frequency once-per-instance
2024-03-13 18:49:28,592 - helpers.py[DEBUG]: config-runcmd already ran (freq=once-per-instance)
2024-03-13 18:49:28,592 - handlers.py[DEBUG]: finish: modules-config/config-runcmd: SUCCESS: config-runcmd previously ran
2024-03-13 18:49:28,592 - main.py[DEBUG]: Ran 3 modules with 0 failures
2024-03-13 18:49:28,592 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpq2a2w7fc) - w: [644] 597 bytes/chars
2024-03-13 18:49:28,592 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2024-03-13 18:49:28,592 - util.py[DEBUG]: Read 16 bytes from /proc/uptime
2024-03-13 18:49:28,592 - util.py[DEBUG]: cloud-init mode 'modules' took 0.164 seconds (0.16)
2024-03-13 18:49:28,593 - handlers.py[DEBUG]: finish: modules-config: SUCCESS: running modules for config
2024-03-13 18:49:35,204 - util.py[DEBUG]: Cloud-init v. 23.3-8.1 running 'modules:final' at Wed, 13 Mar 2024 18:49:35 +0000. Up 1856.29 seconds.
2024-03-13 18:49:35,206 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:49:35,206 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:49:35,209 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:49:35,209 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:49:35,211 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:49:35,211 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:49:35,212 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:49:35,213 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:49:35,214 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:49:35,214 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:49:35,215 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:49:35,215 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:49:35,217 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:49:35,217 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:49:35,218 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:49:35,219 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:49:35,220 - util.py[DEBUG]: Reading from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
2024-03-13 18:49:35,220 - util.py[DEBUG]: Read 136743 bytes from /usr/lib/python3.11/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
2024-03-13 18:49:35,222 - stages.py[DEBUG]: Using distro class 
2024-03-13 18:49:35,223 - modules.py[INFO]: Skipping modules 'salt-minion,phone-home,power-state-change' because no applicable config is provided.
2024-03-13 18:49:35,223 - modules.py[DEBUG]: Running module scripts-vendor () with frequency once-per-instance
2024-03-13 18:49:35,224 - handlers.py[DEBUG]: start: modules-final/config-scripts-vendor: running config-scripts-vendor with frequency once-per-instance
2024-03-13 18:49:35,224 - helpers.py[DEBUG]: config-scripts-vendor already ran (freq=once-per-instance)
2024-03-13 18:49:35,224 - handlers.py[DEBUG]: finish: modules-final/config-scripts-vendor: SUCCESS: config-scripts-vendor previously ran
2024-03-13 18:49:35,224 - modules.py[DEBUG]: Running module scripts-per-once () with frequency once
2024-03-13 18:49:35,224 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-once: running config-scripts-per-once with frequency once
2024-03-13 18:49:35,224 - helpers.py[DEBUG]: config-scripts-per-once already ran (freq=once)
2024-03-13 18:49:35,224 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-once: SUCCESS: config-scripts-per-once previously ran
2024-03-13 18:49:35,224 - modules.py[DEBUG]: Running module scripts-per-boot () with frequency always
2024-03-13 18:49:35,225 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-boot: running config-scripts-per-boot with frequency always
2024-03-13 18:49:35,225 - helpers.py[DEBUG]: Running config-scripts-per-boot using lock ()
2024-03-13 18:49:35,225 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-boot: SUCCESS: config-scripts-per-boot ran successfully
2024-03-13 18:49:35,225 - modules.py[DEBUG]: Running module scripts-per-instance () with frequency once-per-instance
2024-03-13 18:49:35,225 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-instance: running config-scripts-per-instance with frequency once-per-instance
2024-03-13 18:49:35,225 - helpers.py[DEBUG]: config-scripts-per-instance already ran (freq=once-per-instance)
2024-03-13 18:49:35,225 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-instance: SUCCESS: config-scripts-per-instance previously ran
2024-03-13 18:49:35,225 - modules.py[DEBUG]: Running module scripts-user () with frequency once-per-instance
2024-03-13 18:49:35,225 - handlers.py[DEBUG]: start: modules-final/config-scripts-user: running config-scripts-user with frequency once-per-instance
2024-03-13 18:49:35,225 - helpers.py[DEBUG]: config-scripts-user already ran (freq=once-per-instance)
2024-03-13 18:49:35,225 - handlers.py[DEBUG]: finish: modules-final/config-scripts-user: SUCCESS: config-scripts-user previously ran
2024-03-13 18:49:35,225 - modules.py[DEBUG]: Running module final-message () with frequency always
2024-03-13 18:49:35,226 - handlers.py[DEBUG]: start: modules-final/config-final-message: running config-final-message with frequency always
2024-03-13 18:49:35,226 - helpers.py[DEBUG]: Running config-final-message using lock ()
2024-03-13 18:49:35,226 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2024-03-13 18:49:35,226 - util.py[DEBUG]: Read 16 bytes from /proc/uptime
2024-03-13 18:49:35,230 - util.py[DEBUG]: Cloud-init v. 23.3-8.1 finished at Wed, 13 Mar 2024 18:49:35 +0000. Datasource DataSourceHetzner.  Up 1856.38 seconds
2024-03-13 18:49:35,230 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/boot-finished - wb: [644] 56 bytes
2024-03-13 18:49:35,234 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/boot-finished (recursive=False)
2024-03-13 18:49:35,240 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/44169089/boot-finished (recursive=False)
2024-03-13 18:49:35,241 - handlers.py[DEBUG]: finish: modules-final/config-final-message: SUCCESS: config-final-message ran successfully
2024-03-13 18:49:35,241 - main.py[DEBUG]: Ran 6 modules with 0 failures
2024-03-13 18:49:35,241 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpwv81szl0) - w: [644] 597 bytes/chars
2024-03-13 18:49:35,242 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/result.json (via temporary file /var/lib/cloud/data/tmpltao_bck) - w: [644] 68 bytes/chars
2024-03-13 18:49:35,242 - util.py[DEBUG]: Creating symbolic link from '/run/cloud-init/result.json' => '../../var/lib/cloud/data/result.json'
2024-03-13 18:49:35,242 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2024-03-13 18:49:35,242 - util.py[DEBUG]: Read 16 bytes from /proc/uptime
2024-03-13 18:49:35,242 - util.py[DEBUG]: cloud-init mode 'modules' took 0.177 seconds (0.17)
2024-03-13 18:49:35,242 - handlers.py[DEBUG]: finish: modules-final: SUCCESS: running modules for final 
$ cat /var/lib/cloud/instance/cloud-config.txt
#cloud-config

# from 1 files
# init.cfg

---
debug: true
growpart:
    devices:
    - /var
hostname: k3s-control-plane-fsn1-xnr
preserve_hostname: true
runcmd:
-   - btrfs
    - filesystem
    - resize
    - max
    - /var
-   - checkmodule
    - -M
    - -m
    - -o
    - /root/kube_hetzner_selinux.mod
    - /root/kube_hetzner_selinux.te
-   - semodule_package
    - -o
    - /root/kube_hetzner_selinux.pp
    - -m
    - /root/kube_hetzner_selinux.mod
-   - semodule
    - -i
    - /root/kube_hetzner_selinux.pp
-   - setsebool
    - -P
    - virt_use_samba
    - '1'
-   - setsebool
    - -P
    - domain_kernel_load_modules
    - '1'
-   - systemctl
    - disable
    - --now
    - rebootmgr.service
-   - systemctl
    - reload
    - NetworkManager
-   - sed
    - -i
    - s/#SystemMaxUse=/SystemMaxUse=3G/g
    - /etc/systemd/journald.conf
-   - sed
    - -i
    - s/#MaxRetentionSec=/MaxRetentionSec=1week/g
    - /etc/systemd/journald.conf
-   - sed
    - -i
    - s/NUMBER_LIMIT="2-10"/NUMBER_LIMIT="4"/g
    - /etc/snapper/configs/root
-   - sed
    - -i
    - s/NUMBER_LIMIT_IMPORTANT="4-10"/NUMBER_LIMIT_IMPORTANT="3"/g
    - /etc/snapper/configs/root
-   - chmod
    - +x
    - /etc/cloud/rename_interface.sh
-   - systemctl
    - restart
    - sshd
-   - systemctl
    - restart
    - NetworkManager
-   - systemctl
    - status
    - NetworkManager
-   - ip
    - route
    - add
    - default
    - via
    - 172.31.1.1
    - dev
    - eth0
-   - truncate
    - -s
    - '0'
    - /var/log/audit/audit.log
ssh_authorized_keys:
- ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIMa5Es7358E4u5u5cVGZ/6E/uOU6A13QtZZZZjmlfIBd
    jhass@Jonnes-MBP.lan
write_files:
-   content: "#!/bin/bash\nset -euo pipefail\n\nsleep 11\n\nINTERFACE=$(ip link show\
        \ | awk '/^3:/{print $2}' | sed 's/://g')\nMAC=$(cat /sys/class/net/$INTERFACE/address)\n\
        \ncat < /etc/udev/rules.d/70-persistent-net.rules\nSUBSYSTEM==\"net\"\
        , ACTION==\"add\", DRIVERS==\"?*\", ATTR{address}==\"$MAC\", NAME=\"eth1\"\
        \nEOF\n\nip link set $INTERFACE down\nip link set $INTERFACE name eth1\nip\
        \ link set eth1 up\n\neth0_connection=$(nmcli -g GENERAL.CONNECTION device\
        \ show eth0)\nnmcli connection modify \"$eth0_connection\" \\\n  con-name\
        \ eth0 \\\n  connection.interface-name eth0\n\neth1_connection=$(nmcli -g\
        \ GENERAL.CONNECTION device show eth1)\nnmcli connection modify \"$eth1_connection\"\
        \ \\\n  con-name eth1 \\\n  connection.interface-name eth1\n\nsystemctl restart\
        \ NetworkManager\n"
    path: /etc/cloud/rename_interface.sh
    permissions: '0744'
-   content: 'Port 22

        PasswordAuthentication no

        X11Forwarding no

        MaxAuthTries 2

        AllowTcpForwarding no

        AllowAgentForwarding no

        AuthorizedKeysFile .ssh/authorized_keys

        '
    path: /etc/ssh/sshd_config.d/kube-hetzner.conf
-   content: 'REBOOT_METHOD=kured

        '
    path: /etc/transactional-update.conf
-   content: '[rancher-k3s-common-stable]

        name=Rancher K3s Common (stable)

        baseurl=https://rpm.rancher.io/k3s/stable/common/microos/noarch

        enabled=1

        gpgcheck=1

        repo_gpgcheck=0

        gpgkey=https://rpm.rancher.io/public.key

        '
    path: /etc/zypp/repos.d/rancher-k3s-common.repo
-   content: "module kube_hetzner_selinux 1.0;\n\nrequire {\n  type kernel_t, bin_t,\
        \ kernel_generic_helper_t, iscsid_t, iscsid_exec_t, var_run_t,\n  init_t,\
        \ unlabeled_t, systemd_logind_t, systemd_hostnamed_t, container_t,\n  cert_t,\
        \ container_var_lib_t, etc_t, usr_t, container_file_t, container_log_t,\n\
        \  container_share_t, container_runtime_exec_t, container_runtime_t, var_log_t,\
        \ proc_t, io_uring_t, fuse_device_t, http_port_t;\n  class key { read view\
        \ };\n  class file { open read execute execute_no_trans create link lock rename\
        \ write append setattr unlink getattr watch };\n  class sock_file { watch\
        \ write create unlink };\n  class unix_dgram_socket create;\n  class unix_stream_socket\
        \ { connectto read write };\n  class dir { add_name create getattr link lock\
        \ read rename remove_name reparent rmdir setattr unlink search write watch\
        \ };\n  class lnk_file { read create };\n  class system module_request;\n\
        \  class filesystem associate;\n  class bpf map_create;\n  class io_uring\
        \ sqpoll;\n  class anon_inode create;\n  class tcp_socket name_connect;\n\
        \  class chr_file { open read write };\n}\n\n#============= kernel_generic_helper_t\
        \ ==============\nallow kernel_generic_helper_t bin_t:file execute_no_trans;\n\
        allow kernel_generic_helper_t kernel_t:key { read view };\nallow kernel_generic_helper_t\
        \ self:unix_dgram_socket create;\n\n#============= iscsid_t ==============\n\
        allow iscsid_t iscsid_exec_t:file execute;\nallow iscsid_t var_run_t:sock_file\
        \ write;\nallow iscsid_t var_run_t:unix_stream_socket connectto;\n\n#=============\
        \ init_t ==============\nallow init_t unlabeled_t:dir { add_name remove_name\
        \ rmdir };\nallow init_t unlabeled_t:lnk_file create;\nallow init_t container_t:file\
        \ { open read };\nallow init_t container_file_t:file { execute execute_no_trans\
        \ };\nallow init_t fuse_device_t:chr_file { open read write };\nallow init_t\
        \ http_port_t:tcp_socket name_connect;\n\n#============= systemd_logind_t\
        \ ==============\nallow systemd_logind_t unlabeled_t:dir search;\n\n#=============\
        \ systemd_hostnamed_t ==============\nallow systemd_hostnamed_t unlabeled_t:dir\
        \ search;\n\n#============= container_t ==============\n# Basic file and directory\
        \ operations for specific types\nallow container_t cert_t:dir read;\nallow\
        \ container_t cert_t:lnk_file read;\nallow container_t cert_t:file { read\
        \ open };\nallow container_t container_var_lib_t:file { create open read write\
        \ rename lock };\nallow container_t etc_t:dir { add_name remove_name write\
        \ create setattr watch };\nallow container_t etc_t:file { create setattr unlink\
        \ write };\nallow container_t etc_t:sock_file { create unlink };\nallow container_t\
        \ usr_t:dir { add_name create getattr link lock read rename remove_name reparent\
        \ rmdir setattr unlink search write };\nallow container_t usr_t:file { append\
        \ create execute getattr link lock read rename setattr unlink write };\n\n\
        # Additional rules for container_t\nallow container_t container_file_t:file\
        \ { open read write append getattr setattr };\nallow container_t container_file_t:sock_file\
        \ watch;\nallow container_t container_log_t:file { open read write append\
        \ getattr setattr };\nallow container_t container_share_t:dir { read write\
        \ add_name remove_name };\nallow container_t container_share_t:file { read\
        \ write create unlink };\nallow container_t container_runtime_exec_t:file\
        \ { read execute execute_no_trans open };\nallow container_t container_runtime_t:unix_stream_socket\
        \ { connectto read write };\nallow container_t kernel_t:system module_request;\n\
        allow container_t container_log_t:dir { read watch };\nallow container_t container_log_t:file\
        \ { open read watch };\nallow container_t container_log_t:lnk_file read;\n\
        allow container_t var_log_t:dir { add_name write };\nallow container_t var_log_t:file\
        \ { create lock open read setattr write };\nallow container_t var_log_t:dir\
        \ remove_name;\nallow container_t var_log_t:file unlink;\nallow container_t\
        \ proc_t:filesystem associate;\nallow container_t self:bpf map_create;\nallow\
        \ container_t io_uring_t:anon_inode create;\nallow container_t self:io_uring\
        \ sqpoll;\nallow container_t io_uring_t:anon_inode { create map read write\
        \ };\n"
    path: /root/kube_hetzner_selinux.te
-   content: IA==
    encoding: base64
    path: /etc/rancher/k3s/registries.yaml
-   content: '[main]

        dns=none

        '
    path: /etc/NetworkManager/conf.d/dns.conf
-   content: 'nameserver 1.1.1.1

        nameserver 8.8.8.8

        nameserver 2606:4700:4700::1111

        '
    path: /etc/resolv.conf
    permissions: '0644'
...

Note how the log has no mention of any write files tasks.

Besides, isn't the cloud-config passed via user_data and isn't that immutable after instance creation anyhow? I haven't observed any changes to the hcloud_server resource from that attribute changing, there's no way to update in the Hetzner console and both the wording on the provider docs and in things like https://community.hetzner.com/tutorials/basic-cloud-config suggest to me it's only possible to set once on creation. So even if rerunning cloud-init would write the files, I don't think it would be enough to just rerun it.

[jhass]

Okay, after some searching, going by https://stackoverflow.com/a/71152408/2199687 what could work I guess is manually updating /var/lib/cloud/instance/cloud-config.txt via a file provisioner and then running cloud-init single --name write-files --frequency always, cloud-init single --name scripts-user --frequency always (possibly more)

[mysticaltech]

Okay, after some searching, going by https://stackoverflow.com/a/71152408/2199687 what could work I guess is manually updating /var/lib/cloud/instance/cloud-config.txt via a file provisioner and then running cloud-init single --name write-files --frequency always, cloud-init single --name scripts-user --frequency always (possibly more)

@jhass Please try it if you can, and PR most welcome!

Otherwise, just to get SElinux going try such a shell script https://chat.openai.com/share/c2ace355-82ce-4df4-a5b4-590e81443cea. But make sure to replace by the latest version of the policy from locals.tf.

[maaft]

hi @mysticaltech

Here's what I noticed:

• running an arm64 cluster for 2-3 weeks without any issues
• without touching the cluster, suddenly some nodes loose network connection and cluster becomes completely broken

For broken nodes:

• no ping working
• can only access broken nodes through other working nodes (via private network ssh)
• from within broken nodes, i cannot even ping google.de
• audit yields huge list of rules

do you have any idea what could have gone wrong here?

Edit On one of the other nodes where network connection through public networking is completely broken, grep "avc: denied" /var/log/audit/audit.log yields no results. What is going on? :-O

not sure if something really weird is going on, since my .te file is huge. But I'll post it anyway.

my_custom_policy.te

module kube_hetzner_selinux 1.0; require { type kernel_t, bin_t, kernel_generic_helper_t, iscsid_t, iscsid_exec_t, var_run_t, init_t, unlabeled_t, systemd_logind_t, systemd_hostnamed_t, container_t, cert_t, container_var_lib_t, etc_t, usr_t, container_file_t, container_log_t, container_share_t, container_runtime_exec_t, container_runtime_t, var_log_t, proc_t, io_uring_t, fuse_device_t, http_port_t, container_var_run_t; class key { read view }; class file { open read execute execute_no_trans create link lock rename write append setattr unlink getattr watch }; class sock_file { watch write create unlink }; class unix_dgram_socket create; class unix_stream_socket { connectto read write }; class dir { add_name create getattr link lock read rename remove_name reparent rmdir setattr unlink search write watch }; class lnk_file { read create }; class system module_request; class filesystem associate; class bpf map_create; class io_uring sqpoll; class anon_inode { create map read write }; class tcp_socket name_connect; class chr_file { open read write }; } #============= kernel_generic_helper_t ============== allow kernel_generic_helper_t bin_t:file execute_no_trans; allow kernel_generic_helper_t kernel_t:key { read view }; allow kernel_generic_helper_t self:unix_dgram_socket create; #============= iscsid_t ============== allow iscsid_t iscsid_exec_t:file execute; allow iscsid_t var_run_t:sock_file write; allow iscsid_t var_run_t:unix_stream_socket connectto; #============= init_t ============== allow init_t unlabeled_t:dir { add_name remove_name rmdir }; allow init_t unlabeled_t:lnk_file create; allow init_t container_t:file { open read }; allow init_t container_file_t:file { execute execute_no_trans }; allow init_t fuse_device_t:chr_file { open read write }; allow init_t http_port_t:tcp_socket name_connect; #============= systemd_logind_t ============== allow systemd_logind_t unlabeled_t:dir search; #============= systemd_hostnamed_t ============== allow systemd_hostnamed_t unlabeled_t:dir search; #============= container_t ============== # Basic file and directory operations for specific types allow container_t cert_t:dir read; allow container_t cert_t:lnk_file read; allow container_t cert_t:file { read open }; allow container_t container_var_lib_t:file { create open read write rename lock }; allow container_t etc_t:dir { add_name remove_name write create setattr watch }; allow container_t etc_t:file { create setattr unlink write }; allow container_t etc_t:sock_file { create unlink }; allow container_t usr_t:dir { add_name create getattr link lock read rename remove_name reparent rmdir setattr unlink search write }; allow container_t usr_t:file { append create execute getattr link lock read rename setattr unlink write }; # Additional rules for container_t allow container_t container_file_t:file { open read write append getattr setattr }; allow container_t container_file_t:sock_file watch; allow container_t container_log_t:file { open read write append getattr setattr }; allow container_t container_log_t:dir read; allow container_t container_share_t:dir { read write add_name remove_name }; allow container_t container_share_t:file { read write create unlink }; allow container_t container_runtime_exec_t:file { read execute execute_no_trans open }; allow container_t container_runtime_t:unix_stream_socket { connectto read write }; allow container_t kernel_t:system module_request; allow container_t container_log_t:dir { read watch }; allow container_t container_log_t:file { open read watch }; allow container_t container_log_t:lnk_file read; allow container_t var_log_t:dir { add_name write }; allow container_t var_log_t:file { create lock open read setattr write }; allow container_t var_log_t:dir remove_name; allow container_t var_log_t:file unlink; allow container_t proc_t:filesystem associate; allow container_t self:bpf map_create; allow container_t self:io_uring sqpoll; allow container_t io_uring_t:anon_inode { create map read write }; allow container_t container_var_run_t:dir { add_name remove_name write }; allow container_t container_var_run_t:file { create open read rename unlink write };

[mysticaltech]

@maaft Apparently sometimes node automatic upgrade breaks the networking changes, we are currently investigating. Please try to see if you can reapply cloud-init manually, maybe it's saved on the machine. Or look at the code to see what it does and do thst manually. If it works for you, we will be able to create a boot script that does that automatically.

[maaft]

@maaft Apparently sometimes node automatic upgrade breaks the networking changes, we are currently investigating. Please try to see if you can reapply cloud-init manually, maybe it's saved on the machine. Or look at the code to see what it does and do thst manually. If it works for you, we will be able to create a boot script that does that automatically.

okay, thanks - will try it later.

What are the current workarounds? Disable automatic upgrades?

Edit: Also, this must be something new. My 1.5 year old cluster that a created with your repo back in the days, continues to do node upgrades successfully.

Edit2:

As suggested, I executed:

sudo cloud-init init
sudo cloud-init modules --mode config
sudo cloud-init modules --mode final

on the failing node. Still no network connection afterwards.

I noticed that the commands issued by cloud-init actually do nothing!

I executed the commands from cat /var/log/cloud-init.log manually, and suddenly my network is working again.

This is highly unstable though and I'm very much interested more stable solution if you have any.

Logs

Cloud-init v. 23.3-8.1 running 'init' at Tue, 23 Apr 2024 10:12:22 +0000. Up 215.38 seconds. ci-info: ++++++++++++++++++++++++++++++++++++++++Net device info++++++++++++++++++++++++++++++++++++++++ ci-info: +--------+------+------------------------------+-----------------+--------+-------------------+ ci-info: | Device | Up | Address | Mask | Scope | Hw-Address | ci-info: +--------+------+------------------------------+-----------------+--------+-------------------+ ci-info: | enp7s0 | True | 10.255.0.101 | 255.255.255.255 | global | 86:00:00:7e:2d:fc | ci-info: | enp7s0 | True | fe80::f88a:c1f2:363d:31b5/64 | . | link | 86:00:00:7e:2d:fc | ci-info: | eth0 | True | 49.13.59.226 | 255.255.255.255 | global | 96:00:03:1b:cd:01 | ci-info: | eth0 | True | fe80::8f1f:5511:4709:5e88/64 | . | link | 96:00:03:1b:cd:01 | ci-info: | lo | True | 127.0.0.1 | 255.0.0.0 | host | . | ci-info: | lo | True | ::1/128 | . | host | . | ci-info: +--------+------+------------------------------+-----------------+--------+-------------------+ ci-info: +++++++++++++++++++++++++++++Route IPv4 info++++++++++++++++++++++++++++++ ci-info: +-------+-------------+------------+-----------------+-----------+-------+ ci-info: | Route | Destination | Gateway | Genmask | Interface | Flags | ci-info: +-------+-------------+------------+-----------------+-----------+-------+ ci-info: | 0 | 0.0.0.0 | 10.0.0.1 | 0.0.0.0 | enp7s0 | UG | ci-info: | 1 | 0.0.0.0 | 172.31.1.1 | 0.0.0.0 | eth0 | UG | ci-info: | 2 | 10.0.0.0 | 10.0.0.1 | 255.0.0.0 | enp7s0 | UG | ci-info: | 3 | 10.0.0.1 | 0.0.0.0 | 255.255.255.255 | enp7s0 | UH | ci-info: | 4 | 172.31.1.1 | 0.0.0.0 | 255.255.255.255 | eth0 | UH | ci-info: | 5 | 172.31.1.1 | 0.0.0.0 | 255.255.255.255 | eth0 | UH | ci-info: +-------+-------------+------------+-----------------+-----------+-------+ ci-info: +++++++++++++++++++Route IPv6 info+++++++++++++++++++ ci-info: +-------+-------------+---------+-----------+-------+ ci-info: | Route | Destination | Gateway | Interface | Flags | ci-info: +-------+-------------+---------+-----------+-------+ ci-info: | 0 | fe80::/64 | :: | enp7s0 | U | ci-info: | 1 | fe80::/64 | :: | eth0 | U | ci-info: | 3 | local | :: | eth0 | U | ci-info: | 4 | local | :: | enp7s0 | U | ci-info: | 5 | multicast | :: | enp7s0 | U | ci-info: | 6 | multicast | :: | eth0 | U | ci-info: +-------+-------------+---------+-----------+-------+ Cloud-init v. 23.3-8.1 running 'modules:config' at Tue, 23 Apr 2024 10:12:28 +0000. Up 221.53 seconds. Cloud-init v. 23.3-8.1 running 'modules:final' at Tue, 23 Apr 2024 10:12:31 +0000. Up 224.38 seconds. Cloud-init v. 23.3-8.1 finished at Tue, 23 Apr 2024 10:12:31 +0000. Datasource DataSourceHetzner. Up 224.45 seconds #cloud-config # from 1 files # init.cfg --- debug: true growpart: devices: - /var hostname: production-control-plane-fsn1-wjz preserve_hostname: true runcmd: - - btrfs - filesystem - resize - max - /var - - semanage - port - -a - -t - ssh_port_t - -p - tcp - '21259' - - checkmodule - -M - -m - -o - /root/kube_hetzner_selinux.mod - /root/kube_hetzner_selinux.te - - semodule_package - -o - /root/kube_hetzner_selinux.pp - -m - /root/kube_hetzner_selinux.mod - - semodule - -i - /root/kube_hetzner_selinux.pp - - setsebool - -P - virt_use_samba - '1' - - setsebool - -P - domain_kernel_load_modules - '1' - - systemctl - disable - --now - rebootmgr.service - - systemctl - reload - NetworkManager - - sed - -i - s/#SystemMaxUse=/SystemMaxUse=3G/g - /etc/systemd/journald.conf - - sed - -i - s/#MaxRetentionSec=/MaxRetentionSec=1week/g - /etc/systemd/journald.conf - - sed - -i - s/NUMBER_LIMIT="2-10"/NUMBER_LIMIT="4"/g - /etc/snapper/configs/root - - sed - -i - s/NUMBER_LIMIT_IMPORTANT="4-10"/NUMBER_LIMIT_IMPORTANT="3"/g - /etc/snapper/configs/root - - chmod - +x - /etc/cloud/rename_interface.sh - - systemctl - restart - sshd - - systemctl - restart - NetworkManager - - systemctl - status - NetworkManager - - ip - route - add - default - via - 172.31.1.1 - dev - eth0 - - truncate - -s - '0' - /var/log/audit/audit.log ssh_authorized_keys: - ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIE52ueclUWvaQrZRY5z9zkEZP/gGBhM+hFK0oQx7byTC mawe.sprenger@denkweit.de write_files: - content: "#!/bin/bash\nset -euo pipefail\n\nsleep 11\n\nINTERFACE=$(ip link show\ \ | awk '/^3:/ print $2 ' | sed 's/://g')\nMAC=$(cat /sys/class/net/$INTERFACE/address)\n\ \ncat < /etc/udev/rules.d/70-persistent-net.rules\nSUBSYSTEM==\"net\"\ , ACTION==\"add\", DRIVERS==\"?*\", ATTR address==\"$MAC\", NAME=\"eth1\"\ \nEOF\n\nip link set $INTERFACE down\nip link set $INTERFACE name eth1\nip\ \ link set eth1 up\n\neth0_connection=$(nmcli -g GENERAL.CONNECTION device\ \ show eth0)\nnmcli connection modify \"$eth0_connection\" \\\n con-name\ \ eth0 \\\n connection.interface-name eth0\n\neth1_connection=$(nmcli -g\ \ GENERAL.CONNECTION device show eth1)\nnmcli connection modify \"$eth1_connection\"\ \ \\\n con-name eth1 \\\n connection.interface-name eth1\n\nsystemctl restart\ \ NetworkManager\n" path: /etc/cloud/rename_interface.sh permissions: '0744' - content: 'Port 21259 PasswordAuthentication no X11Forwarding no MaxAuthTries 4 AllowTcpForwarding no AllowAgentForwarding no AuthorizedKeysFile .ssh/authorized_keys ' path: /etc/ssh/sshd_config.d/kube-hetzner.conf - content: 'REBOOT_METHOD=kured ' path: /etc/transactional-update.conf - content: '[rancher-k3s-common-stable] name=Rancher K3s Common (stable) baseurl=https://rpm.rancher.io/k3s/stable/common/microos/noarch enabled=1 gpgcheck=1 repo_gpgcheck=0 gpgkey=https://rpm.rancher.io/public.key ' path: /etc/zypp/repos.d/rancher-k3s-common.repo - content: "module kube_hetzner_selinux 1.0;\n\nrequire {\n type kernel_t, bin_t,\ \ kernel_generic_helper_t, iscsid_t, iscsid_exec_t, var_run_t,\n init_t,\ \ unlabeled_t, systemd_logind_t, systemd_hostnamed_t, container_t,\n cert_t,\ \ container_var_lib_t, etc_t, usr_t, container_file_t, container_log_t,\n\ \ container_share_t, container_runtime_exec_t, container_runtime_t, var_log_t,\ \ proc_t, io_uring_t, fuse_device_t, http_port_t,\n container_var_run_t;\n\ \ class key { read view };\n class file { open read execute execute_no_trans\ \ create link lock rename write append setattr unlink getattr watch };\n \ \ class sock_file { watch write create unlink };\n class unix_dgram_socket\ \ create;\n class unix_stream_socket { connectto read write };\n class dir\ \ { add_name create getattr link lock read rename remove_name reparent rmdir\ \ setattr unlink search write watch };\n class lnk_file { read create };\n\ \ class system module_request;\n class filesystem associate;\n class bpf\ \ map_create;\n class io_uring sqpoll;\n class anon_inode { create map read\ \ write };\n class tcp_socket name_connect;\n class chr_file { open read\ \ write };\n}\n\n#============= kernel_generic_helper_t ==============\nallow\ \ kernel_generic_helper_t bin_t:file execute_no_trans;\nallow kernel_generic_helper_t\ \ kernel_t:key { read view };\nallow kernel_generic_helper_t self:unix_dgram_socket\ \ create;\n\n#============= iscsid_t ==============\nallow iscsid_t iscsid_exec_t:file\ \ execute;\nallow iscsid_t var_run_t:sock_file write;\nallow iscsid_t var_run_t:unix_stream_socket\ \ connectto;\n\n#============= init_t ==============\nallow init_t unlabeled_t:dir\ \ { add_name remove_name rmdir };\nallow init_t unlabeled_t:lnk_file create;\n\ allow init_t container_t:file { open read };\nallow init_t container_file_t:file\ \ { execute execute_no_trans };\nallow init_t fuse_device_t:chr_file { open\ \ read write };\nallow init_t http_port_t:tcp_socket name_connect;\n\n#=============\ \ systemd_logind_t ==============\nallow systemd_logind_t unlabeled_t:dir\ \ search;\n\n#============= systemd_hostnamed_t ==============\nallow systemd_hostnamed_t\ \ unlabeled_t:dir search;\n\n#============= container_t ==============\n#\ \ Basic file and directory operations for specific types\nallow container_t\ \ cert_t:dir read;\nallow container_t cert_t:lnk_file read;\nallow container_t\ \ cert_t:file { read open };\nallow container_t container_var_lib_t:file {\ \ create open read write rename lock };\nallow container_t etc_t:dir { add_name\ \ remove_name write create setattr watch };\nallow container_t etc_t:file\ \ { create setattr unlink write };\nallow container_t etc_t:sock_file { create\ \ unlink };\nallow container_t usr_t:dir { add_name create getattr link lock\ \ read rename remove_name reparent rmdir setattr unlink search write };\n\ allow container_t usr_t:file { append create execute getattr link lock read\ \ rename setattr unlink write };\n\n# Additional rules for container_t\nallow\ \ container_t container_file_t:file { open read write append getattr setattr\ \ };\nallow container_t container_file_t:sock_file watch;\nallow container_t\ \ container_log_t:file { open read write append getattr setattr };\nallow\ \ container_t container_log_t:dir read;\nallow container_t container_share_t:dir\ \ { read write add_name remove_name };\nallow container_t container_share_t:file\ \ { read write create unlink };\nallow container_t container_runtime_exec_t:file\ \ { read execute execute_no_trans open };\nallow container_t container_runtime_t:unix_stream_socket\ \ { connectto read write };\nallow container_t kernel_t:system module_request;\n\ allow container_t container_log_t:dir { read watch };\nallow container_t container_log_t:file\ \ { open read watch };\nallow container_t container_log_t:lnk_file read;\n\ allow container_t var_log_t:dir { add_name write };\nallow container_t var_log_t:file\ \ { create lock open read setattr write };\nallow container_t var_log_t:dir\ \ remove_name;\nallow container_t var_log_t:file unlink;\nallow container_t\ \ proc_t:filesystem associate;\nallow container_t self:bpf map_create;\nallow\ \ container_t self:io_uring sqpoll;\nallow container_t io_uring_t:anon_inode\ \ { create map read write };\nallow container_t container_var_run_t:dir {\ \ add_name remove_name write };\nallow container_t container_var_run_t:file\ \ { create open read rename unlink write };\n" path: /root/kube_hetzner_selinux.te - content: IA== encoding: base64 path: /etc/rancher/k3s/registries.yaml - content: '[main] dns=none ' path: /etc/NetworkManager/conf.d/dns.conf - content: 'nameserver 1.1.1.1 nameserver 8.8.8.8 nameserver 2606:4700:4700::1111 ' path: /etc/resolv.conf permissions: '0644' ...

[mysticaltech]

@maaft Thanks for confirming and trying it out. With that I can work on a permanent fix. Will do ASAP 🙏

@kube-hetzner/maintainers FYI

[mysticaltech]

And yes, turning off upgrade would solve that, but not necessary, will create a fix. Probably a systemctl shell that run after each reboot to make sure everything is kosher.

[jhass]

Forcing a re-run of cloud-init requires commands like cloud-init single --frequency always --name <> with the name value set to write_files, runcmd etc.

However that seems rather brittle because 1. cloud-init files are never updated after node creation (changing user_data has no effect after node creation) and 2. if they were to be updated manually with a provisioner one might forget to add or remove a module from the boot command as the config is changed.

I guess one approach to workaround this somewhat is to reduce the cloud init config to the bare minimum of just invoking a script that does the setup and have that script reprovisioned. That should also help with updating the SELinux rules I guess.

Nonetheless the automatic "atomic" updates somehow rolling back the system prior the first cloud-init run (without rerunning cloud-init since the state for that is in a stateful part of the system) seems like a deeper issue that shouldn't be just hacked around :/ I've had to completely remove and re-add nodes due to this because even re-initializing the node through a combination of forced cloud-init reruns and manually tainting terraform state didn't help since I couldn't recover the kubelet's node key in that state sometimes.

[maaft]

@jhass totally agree, the underlying issue has to be fixed

[maaft]

@mysticaltech Hey friend! Did you have time to investigate this issue? Anything I can do to help?

[mysticaltech]

@maaft Today will put my head on this, it will be fixed. Keep you posted 🙏