After I executed :
select * from cloud.user_ip_address where removed is null and allocated is null
and state !='Free';
I saw this (export as insert):
INSERT INTO cloud.user_ip_address
(uuid,account_id,domain_id,public_ip_address,data_center_id,source_nat,allocated,vlan_db_id,one_to_one_nat,vm_id,state,mac_address,source_network_id,network_id,physical_network_id,is_system,vpc_id,dnat_vmip,is_portable,display,removed,created,rule_state,forsystemvms)
VALUES
('fd4a170b-127e-444d-bf7d-b6ad5529122b',NULL,NULL,'217.xx.2xx.12',7,0,NULL,63,0,NULL,'Allocated',1163,247,NULL,213,0,NULL,NULL,0,1,NULL,NULL,NULL,0);
There was no date for Allocated, it was with NULL.
Thank you,
Cristian
-----Original Message-----
From: Daan Hoogland <daan.hoogl...@gmail.com>
Sent: Thursday, November 16, 2023 5:33 PM
To: users@cloudstack.apache.org
Subject: Re: Failed to fetch any free - False - ACS 4.18.1
just to recap Christian,
You had one with state free and removed null and now it works again?
Even though there where free IP before? that should not have been a problem. I
think that is a bug. Can you exact how you fixed it?
On Thu, Nov 16, 2023 at 4:26 PM <cristian.c@istream.today> wrote:
>
> 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$assignAndAllocateIpAdd
> > re
> > ssEntr
> > > y$0(IpAddressManagerImpl.java:374)
> > >
> > > at
> > > com.cloud.utils.db.Transaction.execute(Transaction.java:40)
> > >
> > > at
> > >
> > com.cloud.network.IpAddressManagerImpl.assignAndAllocateIpAddressEnt
> > ry
> > (IpAdd
> > > ressManagerImpl.java:339)
> > >
> > > at
> > >
> > com.cloud.network.IpAddressManagerImpl.fetchNewPublicIp(IpAddressMan
> > ag
> > erImpl
> > > .java:821)
> > >
> > > at
> > >
> > com.cloud.network.IpAddressManagerImpl.fetchNewPublicIp(IpAddressMan
> > ag
> > erImpl
> > > .java:810)
> > >
> > > at
> > >
> > com.cloud.network.IpAddressManagerImpl.assignPublicIpAddress(IpAddre
> > ss
> > Manage
> > > rImpl.java:778)
> > >
> > > at
> > >
> > com.cloud.network.IpAddressManagerImpl$10.doInTransactionWithoutResu
> > lt
> > (IpAdd
> > > ressManagerImpl.java:2240)
> > >
> > > at
> > >
> > com.cloud.utils.db.TransactionCallbackWithExceptionNoReturn.doInTran
> > sa
> > ction(
> > > TransactionCallbackWithExceptionNoReturn.java:25)
> > >
> > > at
> > >
> > com.cloud.utils.db.TransactionCallbackWithExceptionNoReturn.doInTran
> > sa
> > ction(
> > > TransactionCallbackWithExceptionNoReturn.java:21)
> > >
> > > at
> > > com.cloud.utils.db.Transaction.execute(Transaction.java:40)
> > >
> > > at
> > >
> > com.cloud.network.IpAddressManagerImpl.allocateDirectIp(IpAddressMan
> > ag
> > erImpl
> > > .java:2220)
> > >
> > > at
> > >
> > com.cloud.network.guru.DirectNetworkGuru$1.doInTransactionWithoutRes
> > ul
> > t(Dire
> > > ctNetworkGuru.java:324)
> > >
> > > at
> > >
> > com.cloud.utils.db.TransactionCallbackWithExceptionNoReturn.doInTran
> > sa
> > ction(
> > > TransactionCallbackWithExceptionNoReturn.java:25)
> > >
> > > at
> > >
> > com.cloud.utils.db.TransactionCallbackWithExceptionNoReturn.doInTran
> > sa
> > 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.alloc
> > at
> > eNic(N
> > > etworkOrchestrator.java:1025)
> > >
> > > at
> > >
> > org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.addRe
> > qu
> > estedN
> > >
> > icToNicListWithDeviceNumberAndRetrieveDefaultDevice(NetworkOrchestra
> > to
> > r.java
> > > :877)
> > >
> > > at
> > >
> > org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.alloc
> > at
> > e(Netw
> > > orkOrchestrator.java:850)
> > >
> > > at
> > >
> > com.cloud.vm.VirtualMachineManagerImpl.allocate(VirtualMachineManage
> > rI
> > mpl.ja
> > > va:491)
> > >
> > > at
> > >
> > org.apache.cloudstack.engine.orchestration.CloudOrchestrator.createV
> > ir
> > 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(UserVmManage
> > rI
> > mpl.ja
> > > va:3972)
> > >
> > > at
> > >
> > com.cloud.vm.UserVmManagerImpl.createVirtualMachine(UserVmManagerImpl.
> > java:3
> > > 955)
> > >
> > > at
> > >
> > com.cloud.vm.UserVmManagerImpl.createAdvancedVirtualMachine(UserVmMa
> > na
> > gerImp
> > > l.java:3729)
> > >
> > > at
> > >
> > com.cloud.vm.UserVmManagerImpl.createVirtualMachine(UserVmManagerImpl.
> > java:5
> > > 937)
> > >
> > > at
> > > java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Na
> > > ti
> > > ve
> > > Method)
> > >
> > > at
> > >
> > java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Nativ
> > eM
> > ethodA
> > > ccessorImpl.java:62)
> > >
> > > at
> > >
> > java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(D
> > el
> > egatin
> > > gMethodAccessorImpl.java:43)
> > >
> > > at
> > > java.base/java.lang.reflect.Method.invoke(Method.java:566)
> > >
> > > at
> > >
> > org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflect
> > io
> > n(AopU
> > > tils.java:344)
> > >
> > > at
> > >
> > org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJ
> > oi
> > npoint
> > > (ReflectiveMethodInvocation.java:198)
> > >
> > > at
> > >
> > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed
> > (R
> > eflect
> > > iveMethodInvocation.java:163)
> > >
> > > at
> > >
> > org.springframework.aop.interceptor.ExposeInvocationInterceptor.invo
> > ke
> > (Expos
> > > eInvocationInterceptor.java:97)
> > >
> > > at
> > >
> > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed
> > (R
> > eflect
> > > iveMethodInvocation.java:186)
> > >
> > > at
> > >
> > org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynam
> > ic
> > AopPro
> > > xy.java:215)
> > >
> > > at com.sun.proxy.$Proxy185.createVirtualMachine(Unknown
> > > Source)
> > >
> > > at
> > >
> > org.apache.cloudstack.api.command.user.vm.DeployVMCmd.create(DeployV
> > MC
> > md.jav
> > > a:793)
> > >
> > > at
> > >
> > com.cloud.api.dispatch.CommandCreationWorker.handle(CommandCreationW
> > or
> > ker.ja
> > > va:47)
> > >
> > > at
> > > com.cloud.api.dispatch.DispatchChain.dispatch(DispatchChain.java:3
> > > 7)
> > >
> > > at
> > > com.cloud.api.ApiDispatcher.dispatchCreateCmd(ApiDispatcher.java:8
> > > 8)
> > >
> > > 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:3
> > > 47
> > > )
> > >
> > > at com.cloud.api.ApiServlet$1.run(ApiServlet.java:154)
> > >
> > > at
> > >
> > org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.c
> > al
> > l(Defa
> > > ultManagedContext.java:55)
> > >
> > > at
> > >
> > org.apache.cloudstack.managed.context.impl.DefaultManagedContext.cal
> > lW
> > ithCon
> > > text(DefaultManagedContext.java:102)
> > >
> > > at
> > >
> > org.apache.cloudstack.managed.context.impl.DefaultManagedContext.run
> > Wi
> > 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.ja
> > va
> > :600)
> > >
> > > at
> > >
> > org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.
> > java:1
> > > 27)
> > >
> > > at
> > >
> > org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHand
> > le
> > r.java
> > > :235)
> > >
> > > at
> > >
> > org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHand
> > le
> > r.java
> > > :1624)
> > >
> > > at
> > >
> > org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHand
> > le
> > r.java
> > > :233)
> > >
> > > at
> > >
> > org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHand
> > le
> > r.java
> > > :1440)
> > >
> > > at
> > >
> > org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:
> > > 188)
> > >
> > > at
> > > org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.ja
> > > va
> > > :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.ja
> > va
> > :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.ja
> > > va
> > > :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:10
> > > 4)
> > >
> > > at
> > >
> > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWha
> > tY
> > ouKill
> > > .java:338)
> > >
> > > at
> > >
> > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatW
> > ha
> > tYouKi
> > > ll.java:315)
> > >
> > > at
> > >
> > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(Eat
> > Wh
> > atYouK
> > > ill.java:173)
> > >
> > > at
> > >
> > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYou
> > Ki
> > 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(QueuedThre
> > ad
> > 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
> >
>
--
Daan
