Problem when running Conformance Class: View Service - WMS via REST-API

[hwbllmnn]

I expect to get a valid result and a completing test run when running tests via the REST API.

I try to use https://www.bielefeld01.de/geo/extern_free/wms.php?REQUEST=GetCapabilities&SERVICE=WMS&url=satzungen_wms_641&VERSION=1.3.0 as a test resource. When running this test on an ETF instance (running in docker/k8s), I sometimes get stuck test runs that fail to complete.

We usually delete completed test runs in the ETF after extracting the report, so it's easy to see which test runs are stuck. In these cases (this also happens with other test classes, for example Direct WFS and INSPIRE data sets and data set series metadata) we can request a report, for example https://testsuite.stage.ffm.gdi-de.org/validator/v2/TestRuns/EIDff773b7c-bc7a-45c9-b017-32c72f9fe901/log.

Here's a copy of that report since the reports are automatically deleted after a while:

<?xml version="1.0" encoding="UTF-8"?>
<etf:ApiError xmlns:etf="http://www.interactive-instruments.de/etf/2.0">
    <etf:error>The Object or dependent Objects could not be found and may have already been deleted: TestRunDao: An object with the id &quot;ff773b7c-bc7a-45c9-b017-32c72f9fe901&quot; could not be found!</etf:error>
    <etf:timestamp>1643207005394</etf:timestamp>
    <etf:url>http://gdi-k8s-worker-stage--31989/validator/v2/TestRuns/EIDff773b7c-bc7a-45c9-b017-32c72f9fe901/log</etf:url>
    <etf:id>l.object.with.eid.not.found</etf:id>
    <etf:stacktrace>
        <etf:trace>de.interactive_instruments.exceptions.ObjectWithIdNotFoundException: TestRunDao: An object with the id &quot;ff773b7c-bc7a-45c9-b017-32c72f9fe901&quot; could not be found!</etf:trace>
        <etf:trace>	at de.interactive_instruments.etf.dal.dao.basex.AbstractBsxDao.getById(AbstractBsxDao.java:209)</etf:trace>
        <etf:trace>	at de.interactive_instruments.etf.dal.dao.PreparedDtoResolver.getById(PreparedDtoResolver.java:49)</etf:trace>
        <etf:trace>	at de.interactive_instruments.etf.webapp.controller.TestResultController.testRunLog(TestResultController.java:414)</etf:trace>
        <etf:trace> [wrapped] de.interactive_instruments.etf.webapp.controller.LocalizableApiError: de.interactive_instruments.exceptions.ObjectWithIdNotFoundException: TestRunDao: An object with the id &quot;ff773b7c-bc7a-45c9-b017-32c72f9fe901&quot; could not be found!</etf:trace>
        <etf:trace>	at de.interactive_instruments.etf.webapp.controller.TestResultController.testRunLog(TestResultController.java:422)</etf:trace>
        <etf:trace>	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)</etf:trace>
        <etf:trace>	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)</etf:trace>
        <etf:trace>	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)</etf:trace>
        <etf:trace>	at java.lang.reflect.Method.invoke(Method.java:497)</etf:trace>
        <etf:trace>	at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205)</etf:trace>
        <etf:trace>	at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:133)</etf:trace>
        <etf:trace>	at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:97)</etf:trace>
        <etf:trace>	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:827)</etf:trace>
        <etf:trace>	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:738)</etf:trace>
        <etf:trace>	at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85)</etf:trace>
        <etf:trace>	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:967)</etf:trace>
        <etf:trace> [wrapped] org.springframework.web.util.NestedServletException: Handler dispatch failed; nested exception is de.interactive_instruments.etf.webapp.controller.LocalizableApiError: de.interactive_instruments.exceptions.ObjectWithIdNotFoundException: TestRunDao: An object with the id &quot;ff773b7c-bc7a-45c9-b017-32c72f9fe901&quot; could not be found!</etf:trace>
        <etf:trace>	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:982)</etf:trace>
        <etf:trace>	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:901)</etf:trace>
        <etf:trace>	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970)</etf:trace>
        <etf:trace>	at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:861)</etf:trace>
        <etf:trace>	at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)</etf:trace>
        <etf:trace>	at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846)</etf:trace>
        <etf:trace>	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:821)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1685)</etf:trace>
        <etf:trace>	at de.interactive_instruments.etf.webapp.filter.ApiFilter.doFilterInternal(ApiFilter.java:89)</etf:trace>
        <etf:trace>	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)</etf:trace>
        <etf:trace>	at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:347)</etf:trace>
        <etf:trace>	at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:263)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1668)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:581)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1158)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:511)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1090)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:213)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:109)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:119)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.server.Server.handle(Server.java:517)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:308)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:242)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:261)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:75)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceAndRun(ExecuteProduceConsume.java:213)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:147)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:654)</etf:trace>
        <etf:trace>	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)</etf:trace>
        <etf:trace>	at java.lang.Thread.run(Thread.java:745)</etf:trace>
    </etf:stacktrace>
</etf:ApiError>

It seems to me as though some necessary object is deleted but required later on while testing? Anyway, I couldn't find a reference to any of the UUIDs the validator complains about in the projects directory, so it's not a dependency of a test class.

Any ideas on what causes this? Is it a bug in the validator or in the test scripts?

[jenriquesoriano]

Dear @hwbllmnn ,

thanks for reporting this issue.
We have tried to reproduce this behaviour but couldn't do so.
At this point, we are not completely sure of the process you're following to produce the issue.
Please let us describe it here and feel free to complete/add where you consider so in order to help us to fully understand and reproduce the sequence of the issue:

• You're using the REST API sending a WMS service
• You manually delete the test run for a completed service (or for a stuck one?)
• You manually retrieve the test report (log?) for a deleted test run (or for a stuck one?)
• Then you get this inconsistent report (log?)

So here we would kindly ask you to clarify the process (delete test run, request associated test report ?) and the expected result (fully compliant test report?)

Also if you're using some kind of scripts to invoke the services, delete test reports ... ,please let us know if you can share it with us.

Thanks a lot for helping us to better understand the issue.

Best regards,

[hwbllmnn]

Hi @jenriquesoriano ,

yes, we're using the REST API for everything. Since the test run doesn't actually finish but gets stuck, we're not deleting the report. After the test gets stuck, we just use the default UI to retrieve the report.

I cannot really give you some scripts, we're running the validator in an integrated environment and use the etf-client library to access the validator.

Take note that this doesn't happen every time, it just happens sometimes, perhaps due to high load on the ETF. But we get this error a lot. We have multiple instances of the validator running, after a while of operating we have several of the ETF pods completely shut because all slots in the queue are filled with these stuck test runs.

The issue might be related to this open issue reported by @carlospzurita , but that's only a guess.

Best regards

[DanielMartinPerezdeLeon]

Dear @hwbllmnn,

Occasionally, the validator environment may become unstable when certain test objects or test runs are deleted. To ensure a thorough cleansing of the objects and reports utilized in the validator, we typically opt to completely hard-reset the environment after a certain period, essentially creating a fresh environment devoid of any previous volumes or data.

Should there have been any further developments regarding this issue, or if any other problems arise, please do not hesitate to inform us.

Regards,

[jenriquesoriano]

Dear @hwbllmnn ,

we close this issue as a solution has been provided.
Please do not hesitate to open a new issue in case further input is needed.

Best regards