elemental-system-agent vs. rancher-system-agent -- there's only place for one #86

kkaempf · 2022-07-25T07:55:29Z

elemental-operator register writes config for elemental-system-agent (built from github.com/rancher/system-agent)

The only thing elemental-system-agent does is to download and install rancher-system-agent (built, you guessed it, from github.com/rancher/system-agent)

🤦‍♂

We should understand what kind of configs elemental-operator writes, change them to be rancher-system-agent compatible and only start rancher-system-agent. See also #60

Background info: The "official" (?) way to download and start rancher-system-agent is a shell script, provided by the management cluster: curl -fL https://<rancher-url>/system-agent-install.sh

What does this script do ?
What does elemental-operator register do ?

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

Itxaka · 2022-07-25T09:29:30Z

And where does the install comes from? Is it part of the bootstrap plan? Is there a way to modify that bootstrap to not install the agent and just reuse what is on the system?

fgiudici · 2022-07-25T10:14:21Z

Yeah, good questions: I think unveiling them could be part of this card. For the last question ("Is there a way to modify that bootstrap to not install the agent and just reuse what is on the system?" ) from my early investigations I think we can keep our own installation through some configuration drop in file (it seems enough the rancher-system-agent is pointed to our elemental-system-agent configuration). Something anyway that should re-checked and checked better 😅

Itxaka · 2022-07-26T08:46:04Z

I had a look the other day at this and saw:

We use the applyinator thingie to boostrap the node for the first time. That requires a rancher-system-agent(which we run as elemental-system-agent) to run that first plan.
This downloads from rancher a bootstrap.sh file (https://github.com/rancher/elemental-operator/blob/main/pkg/controllers/machineinventoryselector/bootstrap.go#L106)
That script installs the rancher-system-agent binary and systemd files.(here is the full script https://github.com/rancher/system-agent/blob/v0.2.9/install.sh)

So the problem here is that we need a rancher-system-agent to apply the bootstrap scripts, which installs rancher-system-agent

Maybe a quick solution here is to avoid using the boostrap on the operator, and as part of the installed system cloud-config download and execute the boostrap.sh script from rancher so we end up with the proper rancher-system-agent service and files installed. I.E. stop using the elemental-system-agent completely and rely on the rancher-system-agent completely?

Itxaka · 2022-07-26T08:57:46Z

There is also something to take into account and that is that the agent version on rancher settings does not have to match to what we have:

system-agent-version                      v0.2.3

So we may have 0.2.9 in our image but the boostrap script may install a different version :O

kkaempf · 2022-07-26T09:35:19Z

system-agent-version                      v0.2.3

I don't think this is actually being used. From what I've seen, it's version v0.2.7 of rancher-system-agent that gets installed.

Itxaka · 2022-07-26T11:43:32Z

This depends on the rancher version so we should be careful when bumping it. I.e. 2.6.5 comes with 0.2.7 (https://github.com/rancher/rancher/blob/v2.6.5/package/Dockerfile#L61) while 2.6.6 comes with 0.2.8!

Itxaka · 2022-07-26T11:44:13Z

And yeah, its being used, the asses for that version are bundled on the rancher image, so that is where the boostrap picks them. I was just using an old rancher version locally :D

fgiudici · 2022-07-26T12:59:18Z

So the problem here is that we need a rancher-system-agent to apply the bootstrap scripts, which installs rancher-system-agent

Maybe a quick solution here is to avoid using the boostrap on the operator, and as part of the installed system cloud-config download and execute the boostrap.sh script from rancher so we end up with the proper rancher-system-agent service and files installed. I.E. stop using the elemental-system-agent completely and rely on the rancher-system-agent completely?

Yeah, this makes sense to me. As the rancher-system-agent should be synced up with the Rancher Manager instance running seems to me may be better to just rely on the script.

davidcassany · 2022-07-27T09:49:26Z

After having a look, I start to change a bit my mind, probably it is the intended procedure having two agents running. I see the bootstrap script ensures the rancher-system-agent.service is stopped before actually starting to install the rancher-system-agent.service. So I have the feeling that the rancher-system-agent is somehow expected to be reinstalled using this script, this is also a way to sync versions with the rancher manager. So my take is, probably what we need is to ensure the first plan kills any previous installation, but still use the on image installation to run the very first plan.

I think I'll quickly try a couple of options:

Extend the first plan to remove elemental-system-agent
Rename elemental-system-agent to rancher-system-agent, so bootstrap.sh will simply overwrite it.

@Itxaka @fgiudici have you thought or tried something like that?

kkaempf · 2022-07-27T12:02:21Z

I had tried the second option (having only rancher-system-agent on the machine) but it didn't make any difference.

Itxaka · 2022-07-27T12:02:28Z

Nope! maybe @kkaempf tested the second option and that is why he had to rename the agent, so they didnt collide?

kkaempf · 2022-07-27T12:03:02Z

There are also reports from Andrew (in Slack :-/ )

kkaempf · 2022-07-27T12:04:01Z

elemental-system-agent also has a "Condition" in its .service file to not start once rancher-system-agent is deployed.

davidcassany · 2022-07-27T13:09:07Z

I am also testing the second option now and I have something incomplete. Service runs the bootstrap.sh script and redeploys a new racher-system-agent successfully, but that's all, no k3s deployment... nothing else. Now I am trying to figure out who is the actual responsible of calling the k3s deployment as this doesn't look like a matter of the bootstrap.sh

Itxaka · 2022-07-27T16:08:01Z

Now I am trying to figure out who is the actual responsible of calling the k3s deployment as this doesn't look like a matter of the bootstrap.sh

Ohhh boy.

Its a bti complicated. Like the rancher-system-agent has nothing to do with that, it only boostraps the node with whatever plan you have.

The k3s, rke,rke2 stuff is done as part of creating a cluster kind on k8s that has a selector (machineinventoryselector) that matches the node we want to bootstrap.

registration is created
Machine boots with that registration
Machineinventory is created
Machine is boostrapped with elemental-system-agent to install rancher-system-agent with all the config
elemental-system-agent does nothing more
rancher-system-agent is waiting for a new plan
You create a MachineInventorySelectorTemplate, i.e.:

apiVersion: elemental.cattle.io/v1beta1
kind: MachineInventorySelectorTemplate
metadata:
  name: machine-selector-mynewcluster
  namespace: fleet-default
spec:
  template:
    spec:
      selector:
        matchExpressions:
        - key: cluster-id
          operator: In
          values: [ 'mynewcluster' ]

That selector will match any machine that has the cluster-id key set to mynewcluster value
You create a new Cluster that uses that selector to fill its nodes, i.e.:

kind: Cluster
apiVersion: provisioning.cattle.io/v1
metadata:
  name: cluster-mynewcluster
  namespace: fleet-default
spec:
  rkeConfig:
    machinePools:
    - controlPlaneRole: true
      etcdRole: true
      machineConfigRef:
        apiVersion: elemental.cattle.io/v1beta1
        kind: MachineInventorySelectorTemplate
        name: machine-selector-mynewcluster
      name: pool1
      quantity: 1
      unhealthyNodeTimeout: 900s
      workerRole: true
  kubernetesVersion: v1.22.10+rke2r2

That cluster config has the selector we created before so it will pick up the nodes that match that selector.
Also that cluster on the kubernetesVersion it indicates the delivery method. Yeah, weird. v1.22.10+rke2r2 means deploy with rke2, v1.22.10-rancher1-1 means rke1, v1.22.10-k3s1 with k3s.
Now with everything ready, when our node gets the proper label that matches the MachineInventorySelectorTemplate the rancher planner will create a plan and the rancher-system-agent will apply it. This part is black magic, but you can see the things that it does on the journal

[1884]: time="2022-07-27T12:59:36Z" level=info msg="Rancher System Agent version v0.2.7 (65aac83) is starting"
[1884]: time="2022-07-27T12:59:36Z" level=info msg="Using directory /var/lib/rancher/agent/work for work"
[1884]: time="2022-07-27T12:59:36Z" level=info msg="Starting remote watch of plans"
[1884]: time="2022-07-27T12:59:36Z" level=info msg="Starting /v1, Kind=Secret controller"
[1884]: time="2022-07-27T12:59:36Z" level=info msg="Detected first start, force-applying one-time instruction set"
[1884]: time="2022-07-27T12:59:36Z" level=info msg="[Applyinator] Applying one-time instructions for plan with checksum 36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9"
[1884]: time="2022-07-27T12:59:36Z" level=info msg="[Applyinator] Extracting image rancher/system-agent-installer-rke2:v1.22.10-rke2r2 to directory /var/lib/rancher/agent/work/20220727-1259>
[1884]: time="2022-07-27T12:59:36Z" level=info msg="Pulling image index.docker.io/rancher/system-agent-installer-rke2:v1.22.10-rke2r2"
[1884]: time="2022-07-27T12:59:38Z" level=info msg="Extracting file installer.sh to /var/lib/rancher/agent/work/20220727-125936/36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd>
[1884]: time="2022-07-27T12:59:38Z" level=info msg="Extracting file rke2.linux-amd64.tar.gz to /var/lib/rancher/agent/work/20220727-125936/36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236>
[1884]: time="2022-07-27T12:59:39Z" level=info msg="Extracting file sha256sum-amd64.txt to /var/lib/rancher/agent/work/20220727-125936/36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf>
[1884]: time="2022-07-27T12:59:39Z" level=info msg="Extracting file run.sh to /var/lib/rancher/agent/work/20220727-125936/36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0/>
[1884]: time="2022-07-27T12:59:39Z" level=info msg="[Applyinator] Running command: sh [-c run.sh]"

I hope this was useful. I may also be a bit wrong in some places, dont get my full word for it :D

Itxaka · 2022-07-27T16:10:51Z

If you already got the rancher-system-agent running and connected to k8s wiating for plans, you got it working :)

davidcassany · 2022-07-27T17:01:58Z

If you already got the rancher-system-agent running and connected to k8s wiating for plans, you got it working :)

Definitely, this was the easy part.

Now with everything ready, when our node gets the proper label that matches the MachineInventorySelectorTemplate the rancher planner will create a plan and the rancher-system-agent will apply it. This part is black magic, but you can see the things that it does on the journal

What I found so far is that this plan is not executed by rancher-system-agent, but it is by elemental-system-agent. It is a matter of including the elemental connection data to the system agent. After the execution of the bootstarp.sh we have a running rancher-system-agent service, however it doesn't seam to do anything. The obscure plan that gets executed I to provision k8s within the host I only managed to get it applied by using the elemental system agent configuration.

To me it feels like there are two agents listening to different end points. I am wondering now if OS upgrades are also managed by some sort of plan...

Itxaka · 2022-07-27T18:40:35Z

What I found so far is that this plan is not executed by rancher-system-agent, but it is by elemental-system-agent. It is a matter of including the elemental connection data to the system agent. After the execution of the bootstarp.sh we have a running rancher-system-agent service, however it doesn't seam to do anything. The obscure plan that gets executed I to provision k8s within the host I only managed to get it applied by using the elemental system agent configuration.

That is very weird because on my system is the other way around!

elemental-system-agent:

-- Logs begin at Wed 2022-07-27 12:59:12 UTC, end at Wed 2022-07-27 18:28:28 UTC. --
Jul 27 12:59:34 node systemd[1]: Starting Elemental System Agent...
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=info msg="Rancher System Agent version v0.2.9 (bbb6969) is starting"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=info msg="Using directory /var/lib/elemental/agent/work for work"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="Instantiated new image utility with imagesDir: /var/lib/rancher/agent/images, imageCredentialProviderConfig: /var/lib/rancher/credentialprovider/config.yaml, imageCredentialProviderBinDir: /var/lib/rancher/credentialprovider/bin, agentRegistriesFile: /etc/rancher/agent/registries.yaml"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=info msg="Starting remote watch of plans"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=info msg="Starting local watch of plans in /var/lib/elemental/agent/plans"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=info msg="Starting /v1, Kind=Secret controller"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[K8s] Processing secret m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 in namespace fleet-default at generation 0 with resource version 5082"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=info msg="Detected first start, force-applying one-time instruction set"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Applying plan with checksum 44136fa355b3678a1146ad16f7e8649e94fb4fc21fe77e8310c060f61caaff8a"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Writing applied calculated plan contents to historical plan directory /var/lib/elemental/agent/applied"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Reconciling file permissions for /var/lib/elemental/agent/applied/20220727-125934-applied.plan to 0:0 384"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Cleaning working directory before applying /var/lib/elemental/agent/work"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=info msg="[Applyinator] Applying one-time instructions for plan with checksum 44136fa355b3678a1146ad16f7e8649e94fb4fc21fe77e8310c060f61caaff8a"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[K8s] writing an applied checksum value of 44136fa355b3678a1146ad16f7e8649e94fb4fc21fe77e8310c060f61caaff8a to the remote plan"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[K8s] Enqueueing after 5.000000 seconds"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[K8s] updating lastAppliedResourceVersion to 5747"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[K8s] Processing secret m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 in namespace fleet-default at generation 0 with resource version 5747"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[K8s] Applied checksum was the same as the plan from remote. Not applying."
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[K8s] last applied resource version (5747) did not change. running probes, skipping apply."
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Applying plan with checksum 44136fa355b3678a1146ad16f7e8649e94fb4fc21fe77e8310c060f61caaff8a"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Writing applied calculated plan contents to historical plan directory /var/lib/elemental/agent/applied"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Not writing applied plan to file 20220727-125934-applied.plan as the last file written (20220727-125934-applied.plan) had identical contents"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Cleaning working directory before applying /var/lib/elemental/agent/work"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[K8s] writing an applied checksum value of 44136fa355b3678a1146ad16f7e8649e94fb4fc21fe77e8310c060f61caaff8a to the remote plan"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[K8s] Enqueueing after 5.000000 seconds"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[K8s] secret data/string-data did not change, not updating secret"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[K8s] Processing secret m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 in namespace fleet-default at generation 0 with resource version 5754"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Applying plan with checksum 30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Writing applied calculated plan contents to historical plan directory /var/lib/elemental/agent/applied"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Reconciling file permissions for /var/lib/elemental/agent/applied/20220727-125934-applied.plan to 0:0 384"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Writing file /var/lib/rancher/bootstrap.sh"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Reconciling file permissions for /var/lib/rancher/bootstrap.sh to 0:0 448"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Cleaning working directory before applying /var/lib/elemental/agent/work"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=info msg="[Applyinator] Applying one-time instructions for plan with checksum 30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Executing instruction 0 for plan 30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=info msg="[Applyinator] No image provided, creating empty working directory /var/lib/elemental/agent/work/20220727-125934/30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_0"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Requested file permission for /var/lib/elemental/agent/work/20220727-125934/30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_0 was , defaulting to 493"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Reconciling file permissions for /var/lib/elemental/agent/work/20220727-125934/30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_0 to 0:0 493"
Jul 27 12:59:34 node elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=info msg="[Applyinator] Running command: hostnamectl [set-hostname m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3]"
Jul 27 12:59:34 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=info msg="[Applyinator] Command hostnamectl [set-hostname m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3] finished with err: <nil> and exit code: 0"
Jul 27 12:59:34 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Executing instruction 1 for plan 30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d"
Jul 27 12:59:34 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=info msg="[Applyinator] No image provided, creating empty working directory /var/lib/elemental/agent/work/20220727-125934/30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_1"
Jul 27 12:59:34 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Requested file permission for /var/lib/elemental/agent/work/20220727-125934/30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_1 was , defaulting to 493"
Jul 27 12:59:34 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=debug msg="[Applyinator] Reconciling file permissions for /var/lib/elemental/agent/work/20220727-125934/30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_1 to 0:0 493"
Jul 27 12:59:34 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:34Z" level=info msg="[Applyinator] Running command: bash [-c elemental-operator register --label \"elemental.cattle.io/ExternalIP=$(hostname -I | awk '{print $1}')\" --label \"elemental.cattle.io/InternalIP=$(hostname -I | awk '{print $2}')\"]"
Jul 27 12:59:35 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:35Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_1:stderr]: time=\"2022-07-27T12:59:35Z\" level=info msg=\"Operator version v0.4.0, commit cca01301045cdb69aa7155e8b34eaf7eb7029659, commit date 2022-07-27T14:00:57Z\""
Jul 27 12:59:35 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:35Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_1:stderr]: time=\"2022-07-27T12:59:35Z\" level=info msg=\"reading config file /oem/registration/config.yaml\""
Jul 27 12:59:35 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:35Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_1:stderr]: time=\"2022-07-27T12:59:35Z\" level=info msg=\"Using TPMHash 083a45619a0d11adf6ea72bd0bfdde488dec0decf50c8bc42efcc62653b5358d to dial wss://172.18.0.2.sslip.io/elemental/registration/87jd8dsvd7mkr8x9kp87xpwm5h8z2tfzx8b7vk47ntctc6bvsb777x\""
Jul 27 12:59:35 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:35Z" level=info msg="[Applyinator] Command bash [-c elemental-operator register --label \"elemental.cattle.io/ExternalIP=$(hostname -I | awk '{print $1}')\" --label \"elemental.cattle.io/InternalIP=$(hostname -I | awk '{print $2}')\"] finished with err: <nil> and exit code: 0"
Jul 27 12:59:35 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:35Z" level=debug msg="[Applyinator] Executing instruction 2 for plan 30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d"
Jul 27 12:59:35 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:35Z" level=info msg="[Applyinator] No image provided, creating empty working directory /var/lib/elemental/agent/work/20220727-125934/30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2"
Jul 27 12:59:35 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:35Z" level=debug msg="[Applyinator] Requested file permission for /var/lib/elemental/agent/work/20220727-125934/30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2 was , defaulting to 493"
Jul 27 12:59:35 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:35Z" level=debug msg="[Applyinator] Reconciling file permissions for /var/lib/elemental/agent/work/20220727-125934/30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2 to 0:0 493"
Jul 27 12:59:35 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:35Z" level=info msg="[Applyinator] Running command: /var/lib/rancher/bootstrap.sh []"
Jul 27 12:59:35 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:35Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2:stdout]: [INFO]  --no-roles flag passed, unsetting all other requested roles"
Jul 27 12:59:35 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:35Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2:stdout]: [INFO]  Using default agent configuration directory /etc/rancher/agent"
Jul 27 12:59:35 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:35Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2:stdout]: [INFO]  Using default agent var directory /var/lib/rancher/agent"
Jul 27 12:59:35 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:35Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2:stderr]: [WARN]  /usr/local is read-only or a mount point; installing to /opt/rancher-system-agent"
Jul 27 12:59:35 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:35Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2:stdout]: [INFO]  Determined CA is necessary to connect to Rancher"
Jul 27 12:59:35 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:35Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2:stdout]: [INFO]  Successfully downloaded CA certificate"
Jul 27 12:59:35 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:35Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2:stdout]: [INFO]  Value from https://172.18.0.2.sslip.io/cacerts is an x509 certificate"
Jul 27 12:59:35 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:35Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2:stdout]: [INFO]  Successfully tested Rancher connection"
Jul 27 12:59:35 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:35Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2:stdout]: [INFO]  Downloading rancher-system-agent from https://172.18.0.2.sslip.io/assets/rancher-system-agent-amd64"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2:stdout]: [INFO]  Successfully downloaded the rancher-system-agent binary."
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2:stdout]: [INFO]  Generating Cattle ID"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2:stdout]: [INFO]  Successfully downloaded Rancher connection information"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2:stdout]: [INFO]  systemd: Creating service file"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2:stdout]: [INFO]  Creating environment file /etc/systemd/system/rancher-system-agent.env"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2:stdout]: [INFO]  Enabling rancher-system-agent.service"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2:stderr]: Created symlink /etc/systemd/system/multi-user.target.wants/rancher-system-agent.service → /etc/systemd/system/rancher-system-agent.service."
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=info msg="[30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d_2:stdout]: [INFO]  Starting/restarting rancher-system-agent.service"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=info msg="[Applyinator] Command /var/lib/rancher/bootstrap.sh [] finished with err: <nil> and exit code: 0"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=debug msg="[K8s] writing an applied checksum value of 30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d to the remote plan"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=debug msg="[K8s] Enqueueing after 5.000000 seconds"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=debug msg="[K8s] updating lastAppliedResourceVersion to 5777"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=debug msg="[K8s] Processing secret m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 in namespace fleet-default at generation 0 with resource version 5777"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=debug msg="[K8s] Applied checksum was the same as the plan from remote. Not applying."
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=debug msg="[K8s] last applied resource version (5777) did not change. running probes, skipping apply."
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=debug msg="[Applyinator] Applying plan with checksum 30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=debug msg="[Applyinator] Writing applied calculated plan contents to historical plan directory /var/lib/elemental/agent/applied"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=debug msg="[Applyinator] Not writing applied plan to file 20220727-125936-applied.plan as the last file written (20220727-125934-applied.plan) had identical contents"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=debug msg="[Applyinator] Cleaning working directory before applying /var/lib/elemental/agent/work"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=debug msg="[K8s] writing an applied checksum value of 30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d to the remote plan"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=debug msg="[K8s] Enqueueing after 5.000000 seconds"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:36Z" level=debug msg="[K8s] secret data/string-data did not change, not updating secret"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:39Z" level=debug msg="[K8s] Processing secret m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 in namespace fleet-default at generation 0 with resource version 5777"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:39Z" level=debug msg="[K8s] Applied checksum was the same as the plan from remote. Not applying."
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:39Z" level=debug msg="[K8s] last applied resource version (5777) did not change. running probes, skipping apply."
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:39Z" level=debug msg="[Applyinator] Applying plan with checksum 30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:39Z" level=debug msg="[Applyinator] Writing applied calculated plan contents to historical plan directory /var/lib/elemental/agent/applied"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:39Z" level=debug msg="[Applyinator] Not writing applied plan to file 20220727-125939-applied.plan as the last file written (20220727-125934-applied.plan) had identical contents"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:39Z" level=debug msg="[Applyinator] Cleaning working directory before applying /var/lib/elemental/agent/work"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:39Z" level=debug msg="[K8s] writing an applied checksum value of 30fdad9887ea8923cc9e06034bfbe83fec400ebf6bb9ed44693fd07180bf445d to the remote plan"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:39Z" level=debug msg="[K8s] Enqueueing after 5.000000 seconds"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:39Z" level=debug msg="[K8s] secret data/string-data did not change, not updating secret"
Jul 27 12:59:44 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:44Z" level=debug msg="[K8s] Processing secret m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 in namespace fleet-default at generation 0 with resource version 5777"
Jul 27 12:59:44 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:44Z" level=debug msg="[K8s] Applied checksum was the same as the plan from remote. Not applying."
Jul 27 12:59:44 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 elemental-system-agent[1720]: time="2022-07-27T12:59:44Z" level=debug msg="[K8s] last applied resource version (5777) did not change. running probes, skipping apply."

The it just keeps going and going on checking and seeing the same plan, so it does nothing.

rancher-system-agent:

-- Logs begin at Wed 2022-07-27 12:59:12 UTC, end at Wed 2022-07-27 18:28:33 UTC. --
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 systemd[1]: Started Rancher System Agent.
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:36Z" level=info msg="Rancher System Agent version v0.2.7 (65aac83) is starting"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:36Z" level=info msg="Using directory /var/lib/rancher/agent/work for work"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:36Z" level=info msg="Starting remote watch of plans"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:36Z" level=info msg="Starting /v1, Kind=Secret controller"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:36Z" level=info msg="Detected first start, force-applying one-time instruction set"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:36Z" level=info msg="[Applyinator] Applying one-time instructions for plan with checksum 36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:36Z" level=info msg="[Applyinator] Extracting image rancher/system-agent-installer-rke2:v1.22.10-rke2r2 to directory /var/lib/rancher/agent/work/20220727-125936/36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0"
Jul 27 12:59:36 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:36Z" level=info msg="Pulling image index.docker.io/rancher/system-agent-installer-rke2:v1.22.10-rke2r2"
Jul 27 12:59:38 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:38Z" level=info msg="Extracting file installer.sh to /var/lib/rancher/agent/work/20220727-125936/36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0/installer.sh"
Jul 27 12:59:38 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:38Z" level=info msg="Extracting file rke2.linux-amd64.tar.gz to /var/lib/rancher/agent/work/20220727-125936/36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0/rke2.linux-amd64.tar.gz"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="Extracting file sha256sum-amd64.txt to /var/lib/rancher/agent/work/20220727-125936/36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0/sha256sum-amd64.txt"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="Extracting file run.sh to /var/lib/rancher/agent/work/20220727-125936/36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0/run.sh"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[Applyinator] Running command: sh [-c run.sh]"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + SA_INSTALL_PREFIX=/usr/local"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + mkdir -p /var/lib/rancher/rke2"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + SAI_FILE_DIR=/var/lib/rancher/rke2/system-agent-installer"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + RESTART_STAMP_FILE=/var/lib/rancher/rke2/system-agent-installer/rke2_restart_stamp"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + RKE2_SA_ENV_FILE_NAME=rke2-sa.env"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + '[' '!' -d /var/lib/rancher/rke2/system-agent-installer ']'"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + mkdir -p /var/lib/rancher/rke2/system-agent-installer"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + check_target_mountpoint"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + mountpoint -q ''"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + check_target_ro"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + touch /usr/local/.rke2-ro-test"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + rm -rf /usr/local/.rke2-ro-test"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + test 0 -ne 0"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + SYSTEMD_BASE_PATH=/usr/local/lib/systemd/system"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + RKE2_SA_ENV_FILE_PATH=/var/lib/rancher/rke2/system-agent-installer/rke2-sa.env"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + RKE2_SA_ENV_SRV_REF=EnvironmentFile=-/var/lib/rancher/rke2/system-agent-installer/rke2-sa.env"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + '[' -f /var/lib/rancher/rke2/system-agent-installer/rke2_restart_stamp ']'"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + '[' -n 6d99217a6a1d98c6bd9c85a1fbfabf4e0f37b41dca042cf91a3b1bfd43585555 ']'"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + '[' '' '!=' 6d99217a6a1d98c6bd9c85a1fbfabf4e0f37b41dca042cf91a3b1bfd43585555 ']'"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + RESTART=true"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + env INSTALL_RKE2_ARTIFACT_PATH=/var/lib/rancher/agent/work/20220727-125936/36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0 INSTALL_RKE2_TAR_PREFIX=/usr/local installer.sh"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stdout]: [INFO]  staging local checksums from /var/lib/rancher/agent/work/20220727-125936/36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0/sha256sum-amd64.txt"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stdout]: [INFO]  staging tarball from /var/lib/rancher/agent/work/20220727-125936/36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0/rke2.linux-amd64.tar.gz"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stdout]: [INFO]  verifying tarball"
Jul 27 12:59:39 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:39Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stdout]: [INFO]  unpacking tarball file to /usr/local"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + '[' -f /var/lib/rancher/rke2/system-agent-installer/rke2-sa.env ']'"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + OLD_ENV_FILE_PATH_HASH=e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + install -m 600 /dev/null /var/lib/rancher/rke2/system-agent-installer/rke2-sa.env"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: ++ env"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: ++ grep '^RKE2_'"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: ++ true"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + RKE2_ENV="
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + '[' -n '' ']'"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: ++ env"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: ++ grep -Ei '^(NO|HTTP|HTTPS)_PROXY'"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: ++ true"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + PROXY_ENV_INFO="
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + '[' -n '' ']'"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: ++ sha256sum /var/lib/rancher/rke2/system-agent-installer/rke2-sa.env"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: ++ awk '{print $1}'"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + NEW_ENV_FILE_PATH_HASH=e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + '[' e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855 '!=' e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855 ']'"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + '[' -z '' ']'"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + INSTALL_RKE2_TYPE=server"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + grep -q EnvironmentFile=-/var/lib/rancher/rke2/system-agent-installer/rke2-sa.env /usr/local/lib/systemd/system/rke2-server.service"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + echo EnvironmentFile=-/var/lib/rancher/rke2/system-agent-installer/rke2-sa.env"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + '[' -n 6d99217a6a1d98c6bd9c85a1fbfabf4e0f37b41dca042cf91a3b1bfd43585555 ']'"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + echo 6d99217a6a1d98c6bd9c85a1fbfabf4e0f37b41dca042cf91a3b1bfd43585555"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + systemctl daemon-reload"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + '[' '' = true ']'"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + '[' server = server ']'"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + systemctl is-active --quiet rke2-agent"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + systemctl enable rke2-server"
Jul 27 12:59:40 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:40Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: Created symlink /etc/systemd/system/multi-user.target.wants/rke2-server.service → /usr/local/lib/systemd/system/rke2-server.service."
Jul 27 12:59:41 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:41Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + '[' '' = true ']'"
Jul 27 12:59:41 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:41Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + '[' true = true ']'"
Jul 27 12:59:41 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:41Z" level=info msg="[36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0:stderr]: + systemctl --no-block restart rke2-server"
Jul 27 12:59:41 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:41Z" level=info msg="[Applyinator] Command sh [-c run.sh] finished with err: <nil> and exit code: 0"
Jul 27 12:59:41 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:41Z" level=info msg="[Applyinator] No image provided, creating empty working directory /var/lib/rancher/agent/work/20220727-125936/36839a1fece849ee1e998da24db8f8c2a2fa8c7aa342d35236aaaf290c5bd2d9_0"
Jul 27 12:59:41 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:41Z" level=info msg="[Applyinator] Running command: sh [-c rke2 etcd-snapshot list --etcd-s3=false 2>/dev/null]"
Jul 27 12:59:41 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:41Z" level=info msg="[Applyinator] Command sh [-c rke2 etcd-snapshot list --etcd-s3=false 2>/dev/null] finished with err: <nil> and exit code: 1"
Jul 27 12:59:42 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:42Z" level=error msg="error loading CA cert for probe (kube-controller-manager) /var/lib/rancher/rke2/server/tls/kube-controller-manager/kube-controller-manager.crt: open /var/lib/rancher/rke2/server/tls/kube-controller-manager/kube-controller-manager.crt: no such file or directory"
Jul 27 12:59:42 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:42Z" level=error msg="error while appending ca cert to pool for probe kube-controller-manager"
Jul 27 12:59:42 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:42Z" level=error msg="error loading CA cert for probe (kube-scheduler) /var/lib/rancher/rke2/server/tls/kube-scheduler/kube-scheduler.crt: open /var/lib/rancher/rke2/server/tls/kube-scheduler/kube-scheduler.crt: no such file or directory"
Jul 27 12:59:42 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:42Z" level=error msg="error while appending ca cert to pool for probe kube-scheduler"
Jul 27 12:59:42 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:42Z" level=error msg="error encountered during parsing of last run time: parsing time \"\" as \"Mon Jan _2 15:04:05 MST 2006\": cannot parse \"\" as \"Mon\""
Jul 27 12:59:42 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:42Z" level=error msg="error loading CA cert for probe (kube-controller-manager) /var/lib/rancher/rke2/server/tls/kube-controller-manager/kube-controller-manager.crt: open /var/lib/rancher/rke2/server/tls/kube-controller-manager/kube-controller-manager.crt: no such file or directory"
Jul 27 12:59:42 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:42Z" level=error msg="error while appending ca cert to pool for probe kube-controller-manager"
Jul 27 12:59:42 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:42Z" level=error msg="error loading CA cert for probe (kube-scheduler) /var/lib/rancher/rke2/server/tls/kube-scheduler/kube-scheduler.crt: open /var/lib/rancher/rke2/server/tls/kube-scheduler/kube-scheduler.crt: no such file or directory"
Jul 27 12:59:42 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:42Z" level=error msg="error while appending ca cert to pool for probe kube-scheduler"
Jul 27 12:59:42 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:42Z" level=error msg="error encountered during parsing of last run time: parsing time \"\" as \"Mon Jan _2 15:04:05 MST 2006\": cannot parse \"\" as \"Mon\""
Jul 27 12:59:42 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:42Z" level=error msg="error loading CA cert for probe (kube-controller-manager) /var/lib/rancher/rke2/server/tls/kube-controller-manager/kube-controller-manager.crt: open /var/lib/rancher/rke2/server/tls/kube-controller-manager/kube-controller-manager.crt: no such file or directory"
Jul 27 12:59:42 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:42Z" level=error msg="error while appending ca cert to pool for probe kube-controller-manager"
Jul 27 12:59:42 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:42Z" level=error msg="error loading CA cert for probe (kube-scheduler) /var/lib/rancher/rke2/server/tls/kube-scheduler/kube-scheduler.crt: open /var/lib/rancher/rke2/server/tls/kube-scheduler/kube-scheduler.crt: no such file or directory"
Jul 27 12:59:42 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:42Z" level=error msg="error while appending ca cert to pool for probe kube-scheduler"
Jul 27 12:59:42 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:42Z" level=error msg="error encountered during parsing of last run time: parsing time \"\" as \"Mon Jan _2 15:04:05 MST 2006\": cannot parse \"\" as \"Mon\""
Jul 27 12:59:42 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:42Z" level=error msg="error loading CA cert for probe (kube-controller-manager) /var/lib/rancher/rke2/server/tls/kube-controller-manager/kube-controller-manager.crt: open /var/lib/rancher/rke2/server/tls/kube-controller-manager/kube-controller-manager.crt: no such file or directory"
Jul 27 12:59:42 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:42Z" level=error msg="error while appending ca cert to pool for probe kube-controller-manager"
Jul 27 12:59:42 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:42Z" level=error msg="error loading CA cert for probe (kube-scheduler) /var/lib/rancher/rke2/server/tls/kube-scheduler/kube-scheduler.crt: open /var/lib/rancher/rke2/server/tls/kube-scheduler/kube-scheduler.crt: no such file or directory"
Jul 27 12:59:42 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:42Z" level=error msg="error while appending ca cert to pool for probe kube-scheduler"
Jul 27 12:59:47 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:47Z" level=error msg="error encountered during parsing of last run time: parsing time \"\" as \"Mon Jan _2 15:04:05 MST 2006\": cannot parse \"\" as \"Mon\""
Jul 27 12:59:47 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:47Z" level=error msg="error loading CA cert for probe (kube-controller-manager) /var/lib/rancher/rke2/server/tls/kube-controller-manager/kube-controller-manager.crt: open /var/lib/rancher/rke2/server/tls/kube-controller-manager/kube-controller-manager.crt: no such file or directory"
Jul 27 12:59:47 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:47Z" level=error msg="error while appending ca cert to pool for probe kube-controller-manager"
Jul 27 12:59:47 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:47Z" level=error msg="error loading CA cert for probe (kube-scheduler) /var/lib/rancher/rke2/server/tls/kube-scheduler/kube-scheduler.crt: open /var/lib/rancher/rke2/server/tls/kube-scheduler/kube-scheduler.crt: no such file or directory"
Jul 27 12:59:47 m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3 rancher-system-agent[1884]: time="2022-07-27T12:59:47Z" level=error msg="error while appending ca cert to pool for probe kube-scheduler"

Then it keeps going with the install and so on until everything is installed and goes back to check the plan.

I wonder if its a race condition...I guess they are both watching the same namespaces for secrets???

davidcassany · 2022-07-27T18:43:17Z

As far as I understood they both use the same namespace but look at different secrets. I just verified I can deploy a cluster without running the bootstrap.sh script. If I omit that part of the plan it just deploys successfully.

Itxaka · 2022-07-27T18:50:22Z

yep, you are right! Thats another mystery solved!

rancher:

  "namespace": "fleet-default",
  "secretName": "cluster-mynewcluster-bootstrap-template-clmnx-machine-plan"

elemental:

	"namespace":"fleet-default",
	"secretName":"m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3"

Which makes sense, first we watch the namespace for the machine only and then for the plans.

davidcassany · 2022-07-28T07:54:31Z

My question now is, do we need both all the time? Is the elemental system agent end point required after the bootstrap phase? or is the rancher system agent going to be used at all? It is unclear to me who is feeding this plans. I guess this is some rancher manager magic, but not sure how much the elemental-operator controller is involved in there.

That's why my concern now is how elementalOS upgrades are expected to happen, I'd expect them to be executed by plan, a plan pulled from some where.

Itxaka · 2022-07-28T08:14:04Z

I dont think we need both, in fact the only reason the "elemental" one was introduced was for the bootstrap issues that @kkaempf encountered, otherwise the normal agent should be running at all times.

That's why my concern now is how elementalOS upgrades are expected to happen, I'd expect them to be executed by plan, a plan pulled from some where.

Isn there a system-upgrade-controller that should take care of that already? @mudler any idea? I know you love your k8s upgrades :P

kkaempf · 2022-07-28T08:33:48Z

yep, you are right! Thats another mystery solved!

rancher:
  "namespace": "fleet-default",
  "secretName": "cluster-mynewcluster-bootstrap-template-clmnx-machine-plan"
elemental:
	"namespace":"fleet-default",
	"secretName":"m-qemu-standard-pc-q35-ich9-2009-1d566d99-d81a-49ae-b0bb-3"
Which makes sense, first we watch the namespace for the machine only and then for the plans.

Hmm, maybe both are useful. One for per-cluster plans (rancher-system-agent) and the other for per-machine-plans (elemental-system-agent) ?! 🤯

davidcassany · 2022-07-28T08:44:06Z

Hmm, maybe both are useful. One for per-cluster plans (rancher-system-agent) and the other for per-machine-plans (elemental-system-agent) ?!

Exactly this is my main question now. Are both looking for different plans with a different scope? or the default setup of the rancher-system-agent is just looking at the wrong place?

In any case the option I tried as

Rename elemental-system-agent to rancher-system-agent, so bootstrap.sh will simply overwrite it.

won't ever be functional as this stops the former agent service (before the provisioning plan is created|evaluated), overwrites the configuration of the agent with different values and restarts the agent. The running agent at this point will not fetch the provisioning plan anymore...

So, for now, I am more in the mood of keeping both or just the elemental-system-agent.

davidcassany · 2022-08-01T16:06:09Z

Ok, finally I do have a better picture of how these to relate.

I realized I did a wrong tests last week, in fact, as @Itxaka said, elemental-system-agent just spins the bootstrap script to install rancher-system-agent does all the rest. In my env after few hacks I had both configurations mixed and it was hard to identify which of the two was actually doing something.

So elemental-system-agent after the bootstrap is no longer needed. As far as I understood it could be abused later on to run arbitrary commands on per node basis if plans are manually injected to the node associated machine inventory resource secret, since elemental-system-agent is watching this specific secret. However it is unclear to me which is the effect it could have over the machineInventory status. I think none, but not fully convinced.

Also I saw that until the machineInventorySelector is not in ready state the regular rancher provisioning plan does not kick-in. I could not eventually see where the exact link is however this is a requirement. I faced that while trying to merge the two system-agent processes, aka trying to enforce one updates the other, this won't work as the bootstrap scripts stops any running system agent instance and system-agent does not gracefully stop, so any on going plan will not be marked as applied, hence the machineInventorySelector will not reach the ready state. For the same reason adding a simple Conflicts: rancher-system-agent.servicein elemental-system-agent.service unit file will simply fail, the machineInventorySelector never becomes ready even when the bootstrap plan got executed.

IMHO in order to fade out elemental-system-agent, we should do it from a plan executed by rancher-system-agent since it doesn't look like there is a graceful way to make elemental-system-agent to self disable.

In addition I am confident we need the elemental-system-agent process, since at install time there might not be a machine inventory selector and a cluster yet, hence the bootstrap details can be provided at this point. We need some service polling rancher management cluster to kick start the provisioning as soon as the machine inventory selector has a match.

I also could not see a way to configure system-agent to poll multiple secrets, so multiple plans pools require multiple system agent processes.

So all in all I think we just need to agree if we want to keep elemental-system-agent process alive after starting the provisioning or not. I'd say better stop it to prevent confusions.

Itxaka · 2022-08-02T08:13:00Z

In addition I am confident we need the elemental-system-agent process, since at install time there might not be a machine inventory selector and a cluster yet, hence the bootstrap details can be provided at this point. We need some service polling rancher management cluster to kick start the provisioning as soon as the machine inventory selector has a match.

I think this was done on purpose to be able to inject anything to the machine even if its not part of a cluster yet. And based on that we take advantage and do the bootstrap part of installing the rancher-system-agent

From Jacobs patch:

A system agent is installed on elemental to allow arbitrary commands to be executed on the elemental machines. This allows configuration changes to me made to an inventory without that inventory belonging to a cluster.

So all in all I think we just need to agree if we want to keep elemental-system-agent process alive after starting the provisioning or not. I'd say better stop it to prevent confusions.

I would say not. But again how can we stop it properly so it makes the bootstrap plan mark as applied? Because I think that unless its rancher-system-agent the one to stop it, we cannot stop it from the plan itself becuase it will kill itself and never mark the plan as applied. Oneshot service that only runs once? Does the sentinel mode even finishes after executing one plan?

Itxaka · 2022-08-02T08:17:54Z

Maybe we are able to abuse local plans to stop the service from the rancher-system-agent? If we set a local plan that just stops the elemental-system-agent and put into the rancher-system-agent dir, instead of the elemental one, once rancher-system-agent starts it will apply that plan and stop the elemental-system-agent gracefully. By that time elemental-system-agent should have stopped applying the plan and marked as applied?

Itxaka · 2022-08-02T10:07:00Z

Interestingly enough a local plan works as expected:

5460]: time="2022-08-02T09:59:11Z" level=info msg="[Applyinator] Running command: systemctl [stop elemental-system-agent]"
[5460]: time="2022-08-02T09:59:11Z" level=info msg="[Applyinator] Command systemctl [stop elemental-system-agent] finished with err: <nil> and exit code: 0"
[5460]: time="2022-08-02T09:59:11Z" level=info msg="[Applyinator] No image provided, creating empty working directory /var/lib/rancher/agent/work/20220802-095911/dc2538a9967ea9ad0cad262f540>
[5460]: time="2022-08-02T09:59:11Z" level=info msg="[Applyinator] Running command: systemctl [disable elemental-system-agent]"
[5460]: time="2022-08-02T09:59:11Z" level=info msg="[dc2538a9967ea9ad0cad262f540c418b1d92e09b235625bbea44641fcd00d192_1:stderr]: Removed /etc/systemd/system/multi-user.target.wants/elementa>
[5460]: time="2022-08-02T09:59:11Z" level=info msg="Starting /v1, Kind=Secret controller"
[5460]: time="2022-08-02T09:59:11Z" level=info msg="Detected first start, force-applying one-time instruction set"
[5460]: time="2022-08-02T09:59:11Z" level=info msg="[Applyinator] Command systemctl [disable elemental-system-agent] finished with err: <nil> and exit code: 0"

But the problem is that we have no control over the agent config that is installed via the bootstrap script, and that has the localPlans disabled by default. Might be nice to be able to override it somehow to enable the localPlans....

Itxaka · 2022-08-02T10:07:49Z

oh nice CATTLE_LOCAL_ENABLED should be available as part of the bootstrap command ...

davidcassany · 2022-08-02T10:25:31Z

Maybe we are able to abuse local plans to stop the service from the rancher-system-agent? If we set a local plan that just stops the elemental-system-agent and put into the rancher-system-agent dir, instead of the elemental one, once rancher-system-agent starts it will apply that plan and stop the elemental-system-agent gracefully. By that time elemental-system-agent should have stopped applying the plan and marked as applied?

rancher-system-agent is configured by default without local plans enabled... I'd leave it as is I think

davidcassany · 2022-08-02T10:34:54Z

In addition I am confident we need the elemental-system-agent process, since at install time there might not be a machine inventory selector and a cluster yet, hence the bootstrap details can be provided at this point. We need some service polling rancher management cluster to kick start the provisioning as soon as the machine inventory selector has a match.

I think this was done on purpose to be able to inject anything to the machine even if its not part of a cluster yet. And based on that we take advantage and do the bootstrap part of installing the rancher-system-agent

From Jacobs patch:
A system agent is installed on elemental to allow arbitrary commands to be executed on the elemental machines. This allows configuration changes to me made to an inventory without that inventory belonging to a cluster.

Yes, to me it feels that the elemental-system-agent is needed to this exact purpose and only for that. As soon as a node belongs to a cluster I'd say the expectation is to handle all the management form the cluster itself, having a backdoor opened at node level looks like a bad approach to me, it should not be used. If someone ever needs to do something like that they should cook their own soup and provide their own apps and customized setup on top of the regular deployment. We should not provide such a back door IMHO.

Itxaka · 2022-08-02T11:31:13Z

rancher-system-agent is configured by default without local plans enabled... I'd leave it as is I think

FYI, with a simple env var change in the operator it can enable local plans. Plus a very 2 lines simple plan on elemental it all works. elemental starts, bootstraps, marks the plan as applied and launches the rancher agent and that one executes the plan which is just a systemctl stop and that turns out to shut down the elemental agent.

So if we want to fully disable it after bootstrap that is the way to go, all really "simple" to call it somehow :D

kkaempf mentioned this issue Jul 25, 2022

Operator writes config.yaml as JSON #60

Closed

fgiudici self-assigned this Jul 25, 2022

kkaempf mentioned this issue Jul 25, 2022

Rename rancher agent to elemental agent rancher/elemental#206

Merged

davidcassany self-assigned this Aug 2, 2022

davidcassany moved this from 🗳️ To Do to 🏃🏼‍♂️ In Progress in Elemental Aug 2, 2022

davidcassany mentioned this issue Aug 2, 2022

Do not enable elemental-system-agent.service rancher/elemental#234

Merged

davidcassany mentioned this issue Aug 30, 2022

Add local plan to rancher-system-agent to stop elemental-system-agent #146

Merged

davidcassany closed this as completed in #146 Aug 31, 2022

Repository owner moved this from 🏃🏼‍♂️ In Progress to ✅ Done in Elemental Aug 31, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

elemental-system-agent vs. rancher-system-agent -- there's only place for one #86

elemental-system-agent vs. rancher-system-agent -- there's only place for one #86

kkaempf commented Jul 25, 2022 •

edited

Loading

Itxaka commented Jul 25, 2022

fgiudici commented Jul 25, 2022

Itxaka commented Jul 26, 2022 •

edited

Loading

Itxaka commented Jul 26, 2022

kkaempf commented Jul 26, 2022

Itxaka commented Jul 26, 2022

Itxaka commented Jul 26, 2022

fgiudici commented Jul 26, 2022

davidcassany commented Jul 27, 2022

kkaempf commented Jul 27, 2022

Itxaka commented Jul 27, 2022 •

edited

Loading

kkaempf commented Jul 27, 2022

kkaempf commented Jul 27, 2022

davidcassany commented Jul 27, 2022

Itxaka commented Jul 27, 2022

Itxaka commented Jul 27, 2022

davidcassany commented Jul 27, 2022

Itxaka commented Jul 27, 2022

davidcassany commented Jul 27, 2022

Itxaka commented Jul 27, 2022

davidcassany commented Jul 28, 2022 •

edited

Loading

Itxaka commented Jul 28, 2022

kkaempf commented Jul 28, 2022

davidcassany commented Jul 28, 2022

davidcassany commented Aug 1, 2022

Itxaka commented Aug 2, 2022

Itxaka commented Aug 2, 2022

Itxaka commented Aug 2, 2022

Itxaka commented Aug 2, 2022

davidcassany commented Aug 2, 2022

davidcassany commented Aug 2, 2022

Itxaka commented Aug 2, 2022

elemental-system-agent vs. rancher-system-agent -- there's only place for one #86

elemental-system-agent vs. rancher-system-agent -- there's only place for one #86

Comments

kkaempf commented Jul 25, 2022 • edited Loading

Itxaka commented Jul 25, 2022

fgiudici commented Jul 25, 2022

Itxaka commented Jul 26, 2022 • edited Loading

Itxaka commented Jul 26, 2022

kkaempf commented Jul 26, 2022

Itxaka commented Jul 26, 2022

Itxaka commented Jul 26, 2022

fgiudici commented Jul 26, 2022

davidcassany commented Jul 27, 2022

kkaempf commented Jul 27, 2022

Itxaka commented Jul 27, 2022 • edited Loading

kkaempf commented Jul 27, 2022

kkaempf commented Jul 27, 2022

davidcassany commented Jul 27, 2022

Itxaka commented Jul 27, 2022

Itxaka commented Jul 27, 2022

davidcassany commented Jul 27, 2022

Itxaka commented Jul 27, 2022

davidcassany commented Jul 27, 2022

Itxaka commented Jul 27, 2022

davidcassany commented Jul 28, 2022 • edited Loading

Itxaka commented Jul 28, 2022

kkaempf commented Jul 28, 2022

davidcassany commented Jul 28, 2022

davidcassany commented Aug 1, 2022

Itxaka commented Aug 2, 2022

Itxaka commented Aug 2, 2022

Itxaka commented Aug 2, 2022

Itxaka commented Aug 2, 2022

davidcassany commented Aug 2, 2022

davidcassany commented Aug 2, 2022

Itxaka commented Aug 2, 2022

kkaempf commented Jul 25, 2022 •

edited

Loading

Itxaka commented Jul 26, 2022 •

edited

Loading

Itxaka commented Jul 27, 2022 •

edited

Loading

davidcassany commented Jul 28, 2022 •

edited

Loading