Recurring error in the VR Router in ACS 4.20.1 #11240

KuasarCloud · 2025-07-17T20:49:23Z

KuasarCloud
Jul 17, 2025

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 · 2025-07-17T22:36:47Z

KuasarCloud
Jul 17, 2025
Author

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)

0 replies

KuasarCloud · 2025-07-17T22:40:06Z

KuasarCloud
Jul 17, 2025
Author

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

0 replies

rajujith · 2025-07-18T04:26:50Z

rajujith
Jul 18, 2025
Collaborator

@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.

0 replies

KuasarCloud · 2025-07-21T21:30:25Z

KuasarCloud
Jul 21, 2025
Author

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

3 replies

rajujith Jul 22, 2025
Collaborator

@KuasarCloud can you try a new systemVM template?

KuasarCloud Jul 22, 2025
Author

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 Jul 28, 2025
Collaborator

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 · 2025-08-04T14:56:41Z

KuasarCloud
Aug 4, 2025
Author

@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!

0 replies

KuasarCloud · 2025-08-04T15:29:47Z

KuasarCloud
Aug 4, 2025
Author

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

0 replies

KuasarCloud · 2025-09-02T18:30:10Z

KuasarCloud
Sep 2, 2025
Author

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

0 replies

Recurring error in the VR Router in ACS 4.20.1 #11240

Uh oh!

Uh oh!

KuasarCloud Jul 17, 2025

Replies: 7 comments · 3 replies

Uh oh!

KuasarCloud Jul 17, 2025 Author

Uh oh!

KuasarCloud Jul 17, 2025 Author

Uh oh!

Uh oh!

rajujith Jul 18, 2025 Collaborator

Uh oh!

Uh oh!

KuasarCloud Jul 21, 2025 Author

Uh oh!

rajujith Jul 22, 2025 Collaborator

Uh oh!

KuasarCloud Jul 22, 2025 Author

Uh oh!

rajujith Jul 28, 2025 Collaborator

Uh oh!

KuasarCloud Aug 4, 2025 Author

Uh oh!

KuasarCloud Aug 4, 2025 Author

Managment Server

Agent

Uh oh!

KuasarCloud Sep 2, 2025 Author

KuasarCloud
Jul 17, 2025

Replies: 7 comments 3 replies

KuasarCloud
Jul 17, 2025
Author

KuasarCloud
Jul 17, 2025
Author

rajujith
Jul 18, 2025
Collaborator

KuasarCloud
Jul 21, 2025
Author

rajujith Jul 22, 2025
Collaborator

KuasarCloud Jul 22, 2025
Author

rajujith Jul 28, 2025
Collaborator

KuasarCloud
Aug 4, 2025
Author

KuasarCloud
Aug 4, 2025
Author

KuasarCloud
Sep 2, 2025
Author