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
>
