Recurring error in the VR Router in ACS 4.20.1

[KuasarCloud]

Hey community!

After upgrading to 4.20.1 I'm getting this error when trying to start a VM. A VPC clean up is needed everytime, any clue?

2025-07-17 15:44:15,094 WARN  [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-45:[ctx-867b7b76, job-50106/job-50110, ctx-3c4763dd]) (logid:0d91769e) Unable to contact resource. com.cloud.exception.ResourceUnavailableException: Resource [DataCenter:2] is unreachable: Unable to apply dhcp entry on router
	at org.apache.cloudstack.network.topology.BasicNetworkTopology.applyRules(BasicNetworkTopology.java:404)
	at org.apache.cloudstack.network.topology.AdvancedNetworkTopology.applyDhcpEntry(AdvancedNetworkTopology.java:173)
	at com.cloud.network.element.VirtualRouterElement.applyDhcpEntries(VirtualRouterElement.java:1087)
	at com.cloud.network.element.VirtualRouterElement.addDhcpEntry(VirtualRouterElement.java:1055)
	at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepareElement(NetworkOrchestrator.java:1831)
	at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepareNic(NetworkOrchestrator.java:2206)
	at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepare(NetworkOrchestrator.java:2135)
	at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1286)
	at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5486)
	at jdk.internal.reflect.GeneratedMethodAccessor386.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:569)
	at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102)
	at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5610)
	at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99)
	at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:652)
	at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
	at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
	at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
	at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
	at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
	at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:600)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:840)

[KuasarCloud]

These are the logs in the KVM Cloudstack Agent

2025-07-17 15:45:00,070 WARN  [kvm.resource.LibvirtComputingResource] (AgentRequest-Handler-3:[]) (logid:) Exception [Stream closed] occurred when attempting to run command [/usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh update_config.py 169.254.57.165 vm_dhcp_entry.json.a30c8e69-a429-472f-8991-605b1ede4a9c ]. java.io.IOException: Stream closed
        at java.base/java.io.BufferedInputStream.getBufIfOpen(BufferedInputStream.java:168)
        at java.base/java.io.BufferedInputStream.read(BufferedInputStream.java:334)
        at java.base/sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:287)
        at java.base/sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:330)
        at java.base/sun.nio.cs.StreamDecoder.read(StreamDecoder.java:190)
        at java.base/java.io.InputStreamReader.read(InputStreamReader.java:177)
        at java.base/java.io.BufferedReader.fill(BufferedReader.java:162)
        at java.base/java.io.BufferedReader.readLine(BufferedReader.java:329)
        at java.base/java.io.BufferedReader.readLine(BufferedReader.java:396)
        at com.cloud.utils.script.OutputInterpreter.processError(OutputInterpreter.java:41)
        at com.cloud.utils.script.Script.execute(Script.java:305)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeInVR(LibvirtComputingResource.java:562)
        at com.cloud.agent.resource.virtualnetwork.VirtualRoutingResource.applyConfigToVR(VirtualRoutingResource.java:303)
        at com.cloud.agent.resource.virtualnetwork.VirtualRoutingResource.applyConfig(VirtualRoutingResource.java:318)
        at com.cloud.agent.resource.virtualnetwork.VirtualRoutingResource.executeRequest(VirtualRoutingResource.java:165)
        at com.cloud.hypervisor.kvm.resource.wrapper.LibvirtNetworkElementCommandWrapper.execute(LibvirtNetworkElementCommandWrapper.java:35)
        at com.cloud.hypervisor.kvm.resource.wrapper.LibvirtNetworkElementCommandWrapper.execute(LibvirtNetworkElementCommandWrapper.java:29)
        at com.cloud.hypervisor.kvm.resource.wrapper.LibvirtRequestWrapper.execute(LibvirtRequestWrapper.java:78)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1958)
        at com.cloud.agent.Agent.processRequest(Agent.java:779)
        at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:1194)
        at com.cloud.utils.nio.Task.call(Task.java:83)
        at com.cloud.utils.nio.Task.call(Task.java:29)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
        at java.base/java.lang.Thread.run(Thread.java:840)

[KuasarCloud]

I normally clean up the vpc but it's happening every day and only one vpc in one account

[rajujith]

@KuasarCloud can you log in to the VR and check its status? Are there any filesystem errors? Is it not booting? unresponsive? Are you using any memory overcommit?
Register a new system VM template and recreate the VRs.

[KuasarCloud]

Hi @rajujith

I'm not seeing any error in the VR, it works for awhile an then start failing trying to insert an entry in the dnsmasq. In the dnsmasq has this error

root@r-1169-VM:/var/log# tail -f dnsmasq.log Jul 21 21:18:34 dnsmasq[950886]: reading /etc/dnsmasq-resolv.conf Jul 21 21:18:34 dnsmasq[950886]: using nameserver 1.1.1.1#53 Jul 21 21:18:34 dnsmasq[950886]: using nameserver 8.8.8.8#53 Jul 21 21:18:34 dnsmasq[950886]: using only locally-known addresses for hisca.local Jul 21 21:18:34 dnsmasq[950886]: read /etc/hosts - 30 names Jul 21 21:18:34 dnsmasq-dhcp[950886]: read /etc/dhcphosts.txt Jul 21 21:18:34 dnsmasq[950886]: cannot read /etc/dhcpopts.txt: No such file or directory Jul 21 21:18:37 dnsmasq[950886]: read /etc/hosts - 30 names Jul 21 21:18:37 dnsmasq-dhcp[950886]: read /etc/dhcphosts.txt Jul 21 21:18:37 dnsmasq[950886]: cannot read /etc/dhcpopts.txt: No such file or directory

That files is inside /etc/dnsmasq.d

[rajujith]

@KuasarCloud can you try a new systemVM template?

[KuasarCloud]

Thanks @rajujith,

How can I do that?

• Register a new template with the same name?
• When I clean up the VPC how I tell the management server that takes the new template?

Regards

[rajujith]

Register the SystemVM template using URL and select the template type as SYSTEM: http://download.cloudstack.org/systemvm/4.20/systemvmtemplate-4.20.1-x86_64-kvm.qcow2.bz2

Use a new name for the template and update the name at the global settings: router.template.kvm

Restart the management services.
Recreate the VRs.

[KuasarCloud]

@rajujith thanks for replying, not working yet, the curious think about the situation is that is related only to one VR pair in one VPC that has Windows 10 machines!

[KuasarCloud]

I found these logs of interest

Managment Server

2025-08-04 10:00:24,384 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-156:[ctx-fde8a59c, job-51130/job-51134, ctx-9d394f89]) (logid:53cb0025) STATS: Failed to alloc resource from host: Host {"id":2,"name":"xxxxxxx","type":"Routing","uuid":"ba87d8ff-21e0-4f20-8bda-b8fa76453a1c"} reservedCpu: 0, requested cpu: 4798, reservedMem: (0 bytes) 0, requested mem: (4.00 GB) 4294967296

Asking VpcVirtualRouter to prepare for Nic {"broadcastUri":"vxlan://960420","deviceId":0,"iPv4Address":"192.168.30.186","id":1756,"instanceId":506,"reservationId":"db40ff1f-f894-4b08-9842-2c47f59eceb5","uuid":"86263642-87eb-4e96-8a6f-2ad023888c1e"}

2025-08-04 10:00:24,587 DEBUG [o.a.c.n.t.BasicNetworkTopology] (Work-Job-Executor-156:[ctx-fde8a59c, job-51130/job-51134, ctx-9d394f89]) (logid:53cb0025) APPLYING VPC DHCP ENTRY RULES
2025-08-04 10:00:24,588 DEBUG [o.a.c.n.t.BasicNetworkTopology] (Work-Job-Executor-156:[ctx-fde8a59c, job-51130/job-51134, ctx-9d394f89]) (logid:53cb0025) Applying dhcp entry in network Network {"id": 264, "name": "xxxxxxx", "uuid": "c974093f-34c6-4b95-b80e-a67df8dd5a91", "networkofferingid": 47}
2025-08-04 10:00:24,605 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (Work-Job-Executor-156:[ctx-fde8a59c, job-51130/job-51134, ctx-9d394f89]) (logid:53cb0025) Wait time setting on com.cloud.agent.api.routing.DhcpEntryCommand is 1800 seconds

2025-08-04 10:00:25,245 DEBUG [c.c.a.t.Request] (Work-Job-Executor-156:[ctx-fde8a59c, job-51130/job-51134, ctx-9d394f89]) (logid:53cb0025) Seq 2-3132816490792665521: Received: { Ans: , MgmtId: 2199211933721, via: 2(xxxxxxx), Ver: v1, Flags: 10, { GroupAnswer } }
2025-08-04 10:00:25,245 WARN [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-156:[ctx-fde8a59c, job-51130/job-51134, ctx-9d394f89]) (logid:53cb0025) Unable to contact resource. com.cloud.exception.ResourceUnavailableException: Resource [DataCenter:2] is unreachable: Unable to apply dhcp entry on router

Agent

2025-08-04 10:00:22,682 INFO [kvm.resource.LibvirtConnection] (AgentRequest-Handler-1:[]) (logid:) No existing libvirtd connection found. Opening a new one
2025-08-04 10:00:22,683 WARN [kvm.resource.LibvirtConnection] (AgentRequest-Handler-1:[]) (logid:) Can not find a connection for Instance i-122-506-VM. Assuming the default connection.
2025-08-04 10:00:22,777 INFO [resource.virtualnetwork.VirtualRoutingResource] (AgentRequest-Handler-2:[]) (logid:) Fetching health check result for 169.254.242.36 and executing fresh checks: false
2025-08-04 10:00:22,863 WARN [kvm.resource.LibvirtKvmAgentHook] (AgentRequest-Handler-1:[]) (logid:) Groovy script '/etc/cloudstack/agent/hooks/libvirt-vm-state-change.groovy' is not available. Transformations will not be applied.
2025-08-04 10:00:22,863 WARN [kvm.resource.LibvirtKvmAgentHook] (AgentRequest-Handler-1:[]) (logid:) Groovy scripting engine is not initialized. Data transformation skipped.
2025-08-04 10:00:23,395 INFO [resource.virtualnetwork.VirtualRoutingResource] (AgentRequest-Handler-3:[]) (logid:) Fetching health check result for 169.254.195.247 and executing fresh checks: false
2025-08-04 10:00:23,884 INFO [resource.virtualnetwork.VirtualRoutingResource] (AgentRequest-Handler-4:[]) (logid:) Fetching health check result for 169.254.238.34 and executing fresh checks: false
2025-08-04 10:00:24,528 INFO [resource.virtualnetwork.VirtualRoutingResource] (AgentRequest-Handler-5:[]) (logid:) Fetching health check result for 169.254.167.221 and executing fresh checks: false
2025-08-04 10:00:25,203 WARN [kvm.resource.LibvirtComputingResource] (AgentRequest-Handler-1:[]) (logid:) Execution of process [2919709] for command [/usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh update_config.py 169.254.238.34 vm_dhcp_entry.json.49974b02-1631-4db7-baa4-82afdbef3b5a ] failed.
2025-08-04 10:00:25,203 WARN [kvm.resource.LibvirtComputingResource] (AgentRequest-Handler-1:[]) (logid:) Exception [Stream closed] occurred when attempting to run command [/usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh update_config.py 169.254.238.34 vm_dhcp_entry.json.49974b02-1631-4db7-baa4-82afdbef3b5a ]. java.io.IOException: Stream closed

[KuasarCloud]

it didn't happen again, I'm closing this discussion