[IP mgr]? Ip address allocation not found. 404 error

[yanmo96]

When doing create-and-delete-ports_concurrent 50 times with 5 concurrent.
During delete_port will give the Ip address allocation not found error. But from IP Manager log do show it successfully deleted the port.
Rally report and log:

• http://10.213.43.169:8082/7_12_2021/create-and-delete-ports_concurrent.html#/NeutronNetworks.create_and_delete_ports/failures
• http://10.213.43.169:8082/7_12_2021/ym_log/create-and-delete-ports_concurrent

Below are the logs from IP Manager:

2021-07-12 20:02:34.009 DEBUG 1 --- [io-8080-exec-10] o.a.coyote.http11.Http11InputBuffer      : Received [DELETE /ips/c798c193-6902-48aa-aaf3-bdc92b7838f4/10.2.0.2 HTTP/1.1
Content-Length: 0
uber-trace-id: 18bd79477466bcbe:18bd79477466bcbe:0:1
Host: ipmanager-service.default.svc.cluster.local:9004
Connection: Keep-Alive
Accept-Encoding: gzip
User-Agent: okhttp/3.14.7

]
2021-07-12 20:02:34.010 DEBUG 1 --- [io-8080-exec-10] o.apache.catalina.valves.RemoteIpValve   : Incoming request /ips/c798c193-6902-48aa-aaf3-bdc92b7838f4/10.2.0.2 with originalRemoteAddr [172.16.247.211], originalRemoteHost=[172.16.247.211], originalSecure=[false], originalScheme=[http], originalServerName=[ipmanager-service.default.svc.cluster.local], originalServerPort=[9004] will be seen as newRemoteAddr=[172.16.247.211], newRemoteHost=[172.16.247.211], newSecure=[false], newScheme=[http], newServerName=[ipmanager-service.default.svc.cluster.local], newServerPort=[9004]
2021-07-12 20:02:34.010 DEBUG 1 --- [io-8080-exec-10] o.a.c.authenticator.AuthenticatorBase    : Security checking request DELETE /ips/c798c193-6902-48aa-aaf3-bdc92b7838f4/10.2.0.2
2021-07-12 20:02:34.010 DEBUG 1 --- [io-8080-exec-10] org.apache.catalina.realm.RealmBase      :   No applicable constraints defined
2021-07-12 20:02:34.010 DEBUG 1 --- [io-8080-exec-10] o.a.c.authenticator.AuthenticatorBase    : Not subject to any constraint
2021-07-12 20:02:34.011 DEBUG 1 --- [io-8080-exec-10] org.apache.tomcat.util.http.Parameters   : Set encoding to UTF-8
2021-07-12 20:02:34.011 DEBUG 1 --- [io-8080-exec-10] o.s.web.servlet.DispatcherServlet        : DELETE "/ips/c798c193-6902-48aa-aaf3-bdc92b7838f4/10.2.0.2", parameters={}
2021-07-12 20:02:34.011 DEBUG 1 --- [io-8080-exec-10] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to com.futurewei.alcor.privateipmanager.controller.IpAddrController#releaseIpAddr(String, String)
2021-07-12 20:02:34.012 DEBUG 1 --- [io-8080-exec-10] c.f.alcor.common.stats.StatisticsAspect  : Calculating duration of com.futurewei.alcor.privateipmanager.controller.IpAddrController.releaseIpAddr()...
2021-07-12 20:02:34.012 DEBUG 1 --- [io-8080-exec-10] c.f.alcor.common.stats.StatisticsAspect  : Calculating duration of com.futurewei.alcor.privateipmanager.service.implement.IpAddrServiceImpl.releaseIpAddr()...
2021-07-12 20:02:34.012 DEBUG 1 --- [io-8080-exec-10] c.f.a.p.s.implement.IpAddrServiceImpl    : Release ip address, ipAddr: 10.2.0.2
2021-07-12 20:02:34.012 DEBUG 1 --- [io-8080-exec-10] c.f.alcor.common.stats.StatisticsAspect  : Calculating duration of com.futurewei.alcor.privateipmanager.repo.IpAddrRangeRepo.releaseIpAddr()...
2021-07-12 20:02:34.015  INFO 1 --- [io-8080-exec-10] global                                   : Cache IpAddrCache-c798c193-6902-48aa-aaf3-bdc92b7838f4 AtomicityMode is ATOMIC
2021-07-12 20:02:34.020  INFO 1 --- [io-8080-exec-10] c.f.alcor.common.stats.StatisticsAspect  : com.futurewei.alcor.privateipmanager.repo.IpAddrRangeRepo.releaseIpAddr() startTime: 28497960647584041ns, endTime: 28497960655657626ns, duration: 8ms
2021-07-12 20:02:34.020  INFO 1 --- [io-8080-exec-10] c.f.a.p.s.implement.IpAddrServiceImpl    : Release ip address success, result: 10.2.0.2
2021-07-12 20:02:34.020  INFO 1 --- [io-8080-exec-10] c.f.alcor.common.stats.StatisticsAspect  : com.futurewei.alcor.privateipmanager.service.implement.IpAddrServiceImpl.releaseIpAddr() startTime: 28497960647485912ns, endTime: 28497960655756924ns, duration: 8ms
2021-07-12 20:02:34.020  INFO 1 --- [io-8080-exec-10] c.f.alcor.common.stats.StatisticsAspect  : com.futurewei.alcor.privateipmanager.controller.IpAddrController.releaseIpAddr() startTime: 28497960647331643ns, endTime: 28497960655784227ns, duration: 8ms
2021-07-12 20:02:34.021 DEBUG 1 --- [io-8080-exec-10] m.m.a.RequestResponseBodyMethodProcessor : Using 'application/json', given [*/*] and supported [application/json, application/*+json, application/json, application/*+json]
2021-07-12 20:02:34.021 DEBUG 1 --- [io-8080-exec-10] m.m.a.RequestResponseBodyMethodProcessor : Nothing to write: null body
2021-07-12 20:02:34.021 DEBUG 1 --- [io-8080-exec-10] o.s.web.servlet.DispatcherServlet        : Completed 200 OK

[yanmo96]

    
org.springframework.web.util.NestedServletException: Request processing failed; nested exception is java.util.concurrent.CompletionException: org.springframework.web.client.HttpClientErrorException$NotFound: 404 : [{"timestamp":"2021-08-30T23:38:25.008+0000","status":404,"error":"Not Found","message":"Ip address allocation not found","path":"/ips/cabeab2f-aee1-40ba-a11f-ffdd7d9aeeaa/10.187.0.11"}]
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1014)
    at org.springframework.web.servlet.FrameworkServlet.doDelete(FrameworkServlet.java:931)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:666)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:109)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at io.opentracing.contrib.web.servlet.filter.TracingFilter.doFilter(TracingFilter.java:189)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
    at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:747)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:373)
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1594)
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.util.concurrent.CompletionException: org.springframework.web.client.HttpClientErrorException$NotFound: 404 : [{"timestamp":"2021-08-30T23:38:25.008+0000","status":404,"error":"Not Found","message":"Ip address allocation not found","path":"/ips/cabeab2f-aee1-40ba-a11f-ffdd7d9aeeaa/10.187.0.11"}]
    at com.futurewei.alcor.portmanager.request.RequestManager.lambda$sendRequestAsync$0(RequestManager.java:80)
    at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
    ... 1 more
Caused by: org.springframework.web.client.HttpClientErrorException$NotFound: 404 : [{"timestamp":"2021-08-30T23:38:25.008+0000","status":404,"error":"Not Found","message":"Ip address allocation not found","path":"/ips/cabeab2f-aee1-40ba-a11f-ffdd7d9aeeaa/10.187.0.11"}]
    at org.springframework.web.client.HttpClientErrorException.create(HttpClientErrorException.java:113)
    at org.springframework.web.client.DefaultResponseErrorHandler.handleError(DefaultResponseErrorHandler.java:170)
    at org.springframework.web.client.DefaultResponseErrorHandler.handleError(DefaultResponseErrorHandler.java:112)
    at org.springframework.web.client.ResponseErrorHandler.handleError(ResponseErrorHandler.java:63)
    at org.springframework.web.client.RestTemplate.handleResponse(RestTemplate.java:782)
    at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:740)
    at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:674)
    at org.springframework.web.client.RestTemplate.delete(RestTemplate.java:536)
    at com.futurewei.alcor.web.restclient.IpManagerRestClient.releaseIpAddress(IpManagerRestClient.java:114)
    at com.futurewei.alcor.web.restclient.IpManagerRestClient$$FastClassBySpringCGLIB$$c991c926.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:771)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749)
    at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:88)
    at com.futurewei.alcor.common.stats.StatisticsAspect.durationStatistics(StatisticsAspect.java:47)
    at jdk.internal.reflect.GeneratedMethodAccessor67.invoke(Unknown Source)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:644)
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:633)
    at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:95)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:691)
    at com.futurewei.alcor.web.restclient.IpManagerRestClient$$EnhancerBySpringCGLIB$$9ed11708.releaseIpAddress(<generated>)
    at com.futurewei.alcor.portmanager.request.ReleaseIpAddressRequest.send(ReleaseIpAddressRequest.java:42)
    at com.futurewei.alcor.portmanager.request.RequestManager.sendRequest(RequestManager.java:42)
    at com.futurewei.alcor.portmanager.request.RequestManager.sendRequest(RequestManager.java:63)
    at com.futurewei.alcor.portmanager.processor.FixedIpsProcessor.releaseFixedIpAddress(FixedIpsProcessor.java:113)
    at com.futurewei.alcor.portmanager.processor.FixedIpsProcessor.postFetchSubnet(FixedIpsProcessor.java:247)
    at com.futurewei.alcor.portmanager.processor.FixedIpsProcessor.fetchSubnetForDeleteCallBack(FixedIpsProcessor.java:333)
    at com.futurewei.alcor.portmanager.request.RequestManager.sendRequest(RequestManager.java:45)
    at com.futurewei.alcor.portmanager.request.RequestManager.lambda$sendRequestAsync$0(RequestManager.java:78)
    ... 4 more