Hi Wei, Thank you for this! There was 1 IP with removed null and state free. I fixed.
Regards, Cristian -----Original Message----- From: Wei ZHOU <ustcweiz...@gmail.com> Sent: Thursday, November 16, 2023 12:49 PM To: users@cloudstack.apache.org Subject: Re: Failed to fetch any free - False - ACS 4.18.1 Is it possible that an IP is not allocated but the state is not Free ? The sql query below should return empty results. select * from cloud.user_ip_address where removed is null and allocated is null and state !='Free'; -Wei On Thu, 16 Nov 2023 at 10:11, Daan Hoogland <daan.hoogl...@gmail.com> wrote: > strange Christian, > > I checked the code and the only thing I can think of is that creating > a DB lock fails. > > if (_ipAddressDao.lockRow(possibleAddr.getId(), true) != null) { > final IPAddressVO userIp = > _ipAddressDao.findById(possibleAddr.getId()); > if (userIp.getState() == State.Free) { > possibleAddr.setState(State.Allocating); > if (_ipAddressDao.update(possibleAddr.getId(), possibleAddr)) { > finalAddress = possibleAddr; > break; > } > } > } > > Unfortunately, no further logging can be turned on to investigate. > > is this a persistent error (i.e. remains after restarting system > components like the MS and the DB)? > > On Wed, Nov 15, 2023 at 5:52 PM <cristian.c@istream.today> wrote: > > > > > > Hello, > > > > > > > > Today, I tried to deploy new VMs, but I encountered the following error: > > failed to fetch any free public IP address. This is incorrect, as > > even on the dashboard, I can see 12/22 for Public and 172/212 for > > Shared. For > this > > deployment, I used the Shared/guest network. I also checked the > > database > and > > saw 41 free IPs for this zone. > > > > > > Any suggestions? > > > > > > 2023-11-15 11:18:53,441 INFO [c.c.h.v.m.VirtualMachineMO] > > (DirectAgent-19:ctx-a91068e2 usa-nyc-001.test.host, cmd: > > GetVolumeStatsCommand) (logid:851b339a) Look for disk device info > > from volume : ROOT-6215_2.vmdk with base name: ROOT-6215_2 > > > > 2023-11-15 11:18:53,441 INFO [c.c.h.v.m.VirtualMachineMO] > > (DirectAgent-19:ctx-a91068e2 usa-nyc-001.test.host, cmd: > > GetVolumeStatsCommand) (logid:851b339a) Test against disk device, > controller > > key: 1000, unit number: 0 > > > > 2023-11-15 11:18:53,441 INFO [c.c.h.v.m.VirtualMachineMO] > > (DirectAgent-19:ctx-a91068e2 usa-nyc-001.test.host, cmd: > > GetVolumeStatsCommand) (logid:851b339a) Test against disk backing : > [nyc001] > > i-2-6215-VMAMS/ROOT-6215_2.vmdk > > > > 2023-11-15 11:18:53,441 INFO [c.c.h.v.m.VirtualMachineMO] > > (DirectAgent-19:ctx-a91068e2 usa-nyc-001.test.host, cmd: > > GetVolumeStatsCommand) (logid:851b339a) Disk backing : [nyc001] > > i-2-6215-VMAMS/ROOT-6215_2.vmdk matches ==> scsi0:0 > > > > 2023-11-15 11:18:54,194 INFO [c.c.n.NetworkModelImpl] > > (qtp1444635922-323:ctx-a813b819 ctx-3b16875f) (logid:2b3f6d9b) > > Checking permission for account admin > > (17274c5e-d492-11e5-86c3-000c298715c8) on network > > TestHost-Public-NYC (1bece1dc-d9c1-4bff-b5aa-67333a6830ae) > > > > 2023-11-15 11:18:54,309 INFO [c.c.v.VirtualMachineManagerImpl] > > (qtp1444635922-323:ctx-a813b819 ctx-3b16875f) (logid:2b3f6d9b) > > allocating virtual machine from > > template:391d4eab-1506-44be-b743-5ae7bd0f4ad7 with > > hostname:i-2-6262-VMAMS and 1 networks > > > > 2023-11-15 11:18:54,325 ERROR [c.c.n.IpAddressManagerImpl] > > (qtp1444635922-323:ctx-a813b819 ctx-3b16875f) (logid:2b3f6d9b) > > Failed to fetch any free > > > > public IP address > > > > 2023-11-15 11:18:54,340 ERROR [c.c.a.ApiServer] > > (qtp1444635922-323:ctx-a813b819 ctx-3b16875f) (logid:2b3f6d9b) > > unhandled exception executing api command: > > [Ljava.lang.String;@4a8c9f6c > > > > com.cloud.utils.exception.CloudRuntimeException: Failed to fetch any > > free public IP address > > > > at > > > com.cloud.network.IpAddressManagerImpl.lambda$assignAndAllocateIpAddre > ssEntr > > y$0(IpAddressManagerImpl.java:374) > > > > at > > com.cloud.utils.db.Transaction.execute(Transaction.java:40) > > > > at > > > com.cloud.network.IpAddressManagerImpl.assignAndAllocateIpAddressEntry > (IpAdd > > ressManagerImpl.java:339) > > > > at > > > com.cloud.network.IpAddressManagerImpl.fetchNewPublicIp(IpAddressManag > erImpl > > .java:821) > > > > at > > > com.cloud.network.IpAddressManagerImpl.fetchNewPublicIp(IpAddressManag > erImpl > > .java:810) > > > > at > > > com.cloud.network.IpAddressManagerImpl.assignPublicIpAddress(IpAddress > Manage > > rImpl.java:778) > > > > at > > > com.cloud.network.IpAddressManagerImpl$10.doInTransactionWithoutResult > (IpAdd > > ressManagerImpl.java:2240) > > > > at > > > com.cloud.utils.db.TransactionCallbackWithExceptionNoReturn.doInTransa > ction( > > TransactionCallbackWithExceptionNoReturn.java:25) > > > > at > > > com.cloud.utils.db.TransactionCallbackWithExceptionNoReturn.doInTransa > ction( > > TransactionCallbackWithExceptionNoReturn.java:21) > > > > at > > com.cloud.utils.db.Transaction.execute(Transaction.java:40) > > > > at > > > com.cloud.network.IpAddressManagerImpl.allocateDirectIp(IpAddressManag > erImpl > > .java:2220) > > > > at > > > com.cloud.network.guru.DirectNetworkGuru$1.doInTransactionWithoutResul > t(Dire > > ctNetworkGuru.java:324) > > > > at > > > com.cloud.utils.db.TransactionCallbackWithExceptionNoReturn.doInTransa > ction( > > TransactionCallbackWithExceptionNoReturn.java:25) > > > > at > > > com.cloud.utils.db.TransactionCallbackWithExceptionNoReturn.doInTransa > ction( > > TransactionCallbackWithExceptionNoReturn.java:21) > > > > at > > com.cloud.utils.db.Transaction.execute(Transaction.java:40) > > > > at > > > com.cloud.network.guru.DirectNetworkGuru.allocateDirectIp(DirectNetworkGuru. > > java:317) > > > > at > > > com.cloud.network.guru.DirectNetworkGuru.allocate(DirectNetworkGuru.ja > va:290 > > ) > > > > at > > > org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.allocat > eNic(N > > etworkOrchestrator.java:1025) > > > > at > > > org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.addRequ > estedN > > > icToNicListWithDeviceNumberAndRetrieveDefaultDevice(NetworkOrchestrato > r.java > > :877) > > > > at > > > org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.allocat > e(Netw > > orkOrchestrator.java:850) > > > > at > > > com.cloud.vm.VirtualMachineManagerImpl.allocate(VirtualMachineManagerI > mpl.ja > > va:491) > > > > at > > > org.apache.cloudstack.engine.orchestration.CloudOrchestrator.createVir > tualMa > > chine(CloudOrchestrator.java:255) > > > > at > > com.cloud.vm.UserVmManagerImpl.commitUserVm(UserVmManagerImpl.java:4 > > 527) > > > > at > > com.cloud.vm.UserVmManagerImpl.commitUserVm(UserVmManagerImpl.java:4 > > 630) > > > > at > > > com.cloud.vm.UserVmManagerImpl.getUncheckedUserVmResource(UserVmManagerImpl. > > java:4261) > > > > at > > > com.cloud.vm.UserVmManagerImpl.getCheckedUserVmResource(UserVmManagerI > mpl.ja > > va:3972) > > > > at > > > com.cloud.vm.UserVmManagerImpl.createVirtualMachine(UserVmManagerImpl. > java:3 > > 955) > > > > at > > > com.cloud.vm.UserVmManagerImpl.createAdvancedVirtualMachine(UserVmMana > gerImp > > l.java:3729) > > > > at > > > com.cloud.vm.UserVmManagerImpl.createVirtualMachine(UserVmManagerImpl. > java:5 > > 937) > > > > at > > java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Nati > > ve > > Method) > > > > at > > > java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeM > ethodA > > ccessorImpl.java:62) > > > > at > > > java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Del > egatin > > gMethodAccessorImpl.java:43) > > > > at > > java.base/java.lang.reflect.Method.invoke(Method.java:566) > > > > at > > > org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflectio > n(AopU > > tils.java:344) > > > > at > > > org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoi > npoint > > (ReflectiveMethodInvocation.java:198) > > > > at > > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(R > eflect > > iveMethodInvocation.java:163) > > > > at > > > org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke > (Expos > > eInvocationInterceptor.java:97) > > > > at > > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(R > eflect > > iveMethodInvocation.java:186) > > > > at > > > org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamic > AopPro > > xy.java:215) > > > > at com.sun.proxy.$Proxy185.createVirtualMachine(Unknown > > Source) > > > > at > > > org.apache.cloudstack.api.command.user.vm.DeployVMCmd.create(DeployVMC > md.jav > > a:793) > > > > at > > > com.cloud.api.dispatch.CommandCreationWorker.handle(CommandCreationWor > ker.ja > > va:47) > > > > at > > com.cloud.api.dispatch.DispatchChain.dispatch(DispatchChain.java:37) > > > > at > > com.cloud.api.ApiDispatcher.dispatchCreateCmd(ApiDispatcher.java:88) > > > > at com.cloud.api.ApiServer.queueCommand(ApiServer.java:703) > > > > at com.cloud.api.ApiServer.handleRequest(ApiServer.java:603) > > > > at > > com.cloud.api.ApiServlet.processRequestInContext(ApiServlet.java:347 > > ) > > > > at com.cloud.api.ApiServlet$1.run(ApiServlet.java:154) > > > > at > > > org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.cal > l(Defa > > ultManagedContext.java:55) > > > > at > > > org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callW > ithCon > > text(DefaultManagedContext.java:102) > > > > at > > > org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWi > thCont > > ext(DefaultManagedContext.java:52) > > > > at > > com.cloud.api.ApiServlet.processRequest(ApiServlet.java:151) > > > > at com.cloud.api.ApiServlet.doGet(ApiServlet.java:105) > > > > at > > javax.servlet.http.HttpServlet.service(HttpServlet.java:645) > > > > at > > javax.servlet.http.HttpServlet.service(HttpServlet.java:750) > > > > at > > > org.eclipse.jetty.servlet.ServletHolder$NotAsync.service(ServletHolder.java: > > 1450) > > > > at > > org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:79 > > 9) > > > > at > > > org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java: > 554) > > > > at > > > org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.ja > va:143 > > ) > > > > at > > > org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java > :600) > > > > at > > > org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper. > java:1 > > 27) > > > > at > > > org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandle > r.java > > :235) > > > > at > > > org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandle > r.java > > :1624) > > > > at > > > org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandle > r.java > > :233) > > > > at > > > org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandle > r.java > > :1440) > > > > at > > > org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java: > > 188) > > > > at > > org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java > > :505) > > > > at > > > org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java: > > 1594) > > > > at > > > org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java: > > 186) > > > > at > > > org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java: > > 1355) > > > > at > > > org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.ja > va:141 > > ) > > > > at > > > org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.j > ava:77 > > 2) > > > > at > > > org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection. > > java:146) > > > > at > > > org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper. > java:1 > > 27) > > > > at org.eclipse.jetty.server.Server.handle(Server.java:516) > > > > at > > > org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java: > 487) > > > > at > > org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732) > > > > at > org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479) > > > > at > > > org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java > :277) > > > > at > > org.eclipse.jetty.io > .AbstractConnection$ReadCallback.succeeded(AbstractConne > > ction.java:311) > > > > at org.eclipse.jetty.io > .FillInterest.fillable(FillInterest.java:105) > > > > at > > > org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(Ss > lConne > > ction.java:555) > > > > at > > org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java > > :410) > > > > at > > > org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java: > 164) > > > > at org.eclipse.jetty.io > .FillInterest.fillable(FillInterest.java:105) > > > > at > > org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) > > > > at > > > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatY > ouKill > > .java:338) > > > > at > > > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWha > tYouKi > > ll.java:315) > > > > at > > > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWh > atYouK > > ill.java:173) > > > > at > > > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKi > ll.jav > > a:131) > > > > at > > > org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.ru > n(Rese > > rvedThreadExecutor.java:409) > > > > at > > > org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java: > > 883) > > > > at > > > org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThread > Pool.j > > ava:1034) > > > > at java.base/java.lang.Thread.run(Thread.java:829) > > > > 2023-11-15 11:18:54,406 WARN [c.c.a.m.AgentManagerImpl] > > (AgentManager-Handler-1:null) (logid:) Throwing away a request > > because it came through as > > > > the first command on a connect: null > > > > > > > > Regards, > > > > Cristian > > > > > -- > Daan >