search

opengeospatial / ets-wms13

Repository for the Exectutable Test Suite for WMS 1.3.0
Apache License 2.0
2 stars 4 forks source link

[Fatal Error] An invalid XML character was found in the element content of the document. #45

Closed pblottiere closed 7 years ago

pblottiere commented 7 years ago

Hi,

I'm trying to run ets-wms13 on QGIS Server but when I run tests, I have the next issue described in the logfile:

Suite wms-1.3.0:ets-wms13-auto Failed
[Fatal Error] log.xml:42:33: An invalid XML character (Unicode: 0x10) was found in the element content of the document.
[Fatal Error] report_logs.xml:1:9704: Error attempting to parse XML file (href='/srv/tomcat/teamengine/temp/caea4ef4-c62e-44e2-9d51-9999b5d1df32/d1e17333_1/d1e17415_1/d1e3456_1/d1e3506_1/log.xml').
Mar 06, 2017 9:44:26 AM com.sun.jersey.spi.container.ContainerResponse logException
SEVERE: Mapped exception to response: 500 (Internal Server Error)

Versions currently used:

Some scripts are available here to build a Docker container provisioned with Ansible with Teamengine, ets-wms13 and QGIS Server : https://github.com/pblottiere/docker-qgis-ogc-cite.

So I think you can easily reproduce the error.

Thank you for your work!

dstenger commented 7 years ago

Thank you for reporting the issue.

Does the failure occur when you run the tests or when you start the TEAM Engine? Can you please test your service on http://cite.opengeospatial.org/teamengine/ and check whether the same error is occurring? Can you please test an official reference implementation [1] (e.g. [2]) with you locally set up TEAM Engine? Can the ETS handle this service?

[1] https://github.com/opengeospatial/cite/wiki/Reference-Implementations [2] http://cite.deegree.org/deegree-webservices-3.4-RC1/services/wms130?service=WMS&request=GetCapabilities

pblottiere commented 7 years ago

Does the failure occur when you run the tests or when you start the TEAM Engine?

Yes, when I run the tests.

Can you please test an official reference implementation [1] (e.g. [2]) with you locally set up TEAM Engine? Can the ETS handle this service?

I'm sorry but I'm not sure to understand what you want me to do... But the GetCapabilities for QGIS Server seems OK. And the ETS is well running tests until it fails on a specific test (getmap:bbox-minx-eq-maxx I think).

pblottiere commented 7 years ago

And the ETS is well running tests until it fails on a specific test (getmap:bbox-minx-eq-maxx I think).

Actually, I think it's not totally true. I have the feeling that all tests are running but it seems to fail during the reporting step because of the getmap:bbox-minx-eq-maxx result.

pblottiere commented 7 years ago

By the way, I think it's more or less the same issue than the one described in this ticket: https://github.com/opengeospatial/ets-wms13/issues/28

pblottiere commented 7 years ago

@dstenger

Can you please test an official reference implementation [1] (e.g. [2]) with you locally set up TEAM Engine? Can the ETS handle this service?

I tried my local TEAM Engine and it's working fine with geoserver http://cite.demo.opengeo.org:8080/geoserver_wms13/wms?service=wms&request=getcapabilities&version=1.3.0

The report is well published without any errors.

What do you think?

dstenger commented 7 years ago

Thank you for the further analysis. So, we can conclude that the failure definitely results from the service.

dstenger commented 7 years ago

Can you provide us an endpoint to reproduce the error? Also, a short guide how to set up the service with Docker would be fine.

pblottiere commented 7 years ago

I think the easiest way is that I build a ready to use Docker image. Then I'll publish it and you'll be able to use it.

I let you know.

Thank you for your response!

pblottiere commented 7 years ago

@dstenger

You have a ready to use Docker image available thanks to:

$ docker pull oslandia/qgis-server-ogc-cite

Then, to run it:

$ docker run --cap-add=SYS_ADMIN -v /sys/fs/cgroup:/sys/fs/cgroup -d oslandia/qgis-server-ogc-cite

A QGIS Server and my Teamengine setup are both running . To have the getCapabilities result from Qgis Server:

http://<CONTAINER_IP>/qgisserver?REQUEST=GetCapabilities&SERVICE=WMS&VERSION=1.3.0&MAP=/home/user/teamengine_wms_130.qgs

To run Teamengine test suite for WMS 1.3.0 with Qgis Server:

http://<CONTAINER_IP>:8080/teamengine/rest/suites/wms/1.20/run?capabilities-url=http:/
/<CONTAINER_IP>/qgisserver?REQUEST=GetCapabilities%26SERVICE=WMS%26VERSION=1.3.0%26MAP=/home/user/teamengine_wms_130.qgs

The <CONTAINER_IP> can be retrieved with the docker inspect command.

And finally, once logged on the container, you have the log file of Teamengine which describe the failure:

$ cat /srv/tomcat/teamengine/logs/catalina.out
...
...
...
...
******************************************************************************************************************************
               Testing getfeatureinfo:each-queryable-layer type Mandatory in Test Mode with defaultResult Pass (b4fff7c7-6af5-4c54-8005-858f18a2d55c/d1e17333_1/d1e17421_1/d1e9517_1/d1e9608_14)...
                  Assertion: For layer "BasicPolygons", when the QUERY_LAYERS parameter is set to that layer name, the MIME type of the response is valid.
               Test getfeatureinfo:each-queryable-layer Passed
******************************************************************************************************************************
               Testing getfeatureinfo:each-queryable-layer type Mandatory in Test Mode with defaultResult Pass (b4fff7c7-6af5-4c54-8005-858f18a2d55c/d1e17333_1/d1e17421_1/d1e9517_1/d1e9608_15)...
                  Assertion: For layer "Autos", when the QUERY_LAYERS parameter is set to that layer name, the MIME type of the response is valid.
               Test getfeatureinfo:each-queryable-layer Passed
            Test getfeatureinfo:query-layers Passed
         Test getfeatureinfo:main Passed
******************************************************************************************************************************
         Testing dims:main type Mandatory in Test Mode with defaultResult Pass (b4fff7c7-6af5-4c54-8005-858f18a2d55c/d1e17333_1/d1e17423_1)...
            Context: WMS_Capabilities element
            Assertion: Support for dimensional data is correct.
******************************************************************************************************************************
            Testing dims:missing-no-default type Mandatory in Test Mode with defaultResult Pass (b4fff7c7-6af5-4c54-8005-858f18a2d55c/d1e17333_1/d1e17423_1/d1e3310_1)...
               Context: WMS_Capabilities element
               Assertion: When a layer that has a dimension without a default value is requested without supplying the dimension parameter, the response is an exception with code=MissingDimensionValue.
               No Named layers that have a dimension without a default value.
            Test dims:missing-no-default Passed
         Test dims:main Passed
      Test main:data-independent Failed - Inherited
   Test main:main-auto Failed - Inherited
            See the detail test Report /srv/tomcat/teamengine/temp/b4fff7c7-6af5-4c54-8005-858f18a2d55c/log.xml
            See the detail error Report /srv/tomcat/teamengine/temp/b4fff7c7-6af5-4c54-8005-858f18a2d55c/error_log/log.txt
Suite wms-1.3.0:ets-wms13-auto Failed
[Fatal Error] log.xml:42:33: An invalid XML character (Unicode: 0x10) was found in the element content of the document.
[Fatal Error] report_logs.xml:1:10639: Error attempting to parse XML file (href='/srv/tomcat/teamengine/temp/b4fff7c7-6af5-4c54-8005-858f18a2d55c/d1e17333_1/d1e17415_1/d1e3456_1/d1e3506_1/log.xml').
Mar 22, 2017 8:53:37 AM com.sun.jersey.spi.container.ContainerResponse logException
SEVERE: Mapped exception to response: 500 (Internal Server Error)
javax.ws.rs.WebApplicationException
    at com.occamlab.te.spi.jaxrs.resources.TestRunResource.executeTestRun(TestRunResource.java:196)
    at com.occamlab.te.spi.jaxrs.resources.TestRunResource.handleGet(TestRunResource.java:70)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60)
    at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$TypeOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:185)
    at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75)
    at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:302)
    at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108)
    at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)
    at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84)
    at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1542)
    at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1473)
    at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1419)
    at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1409)
    at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:409)
    at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:558)
    at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:733)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:221)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:956)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:436)
    at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1078)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625)
    at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:745)

Thank you for your time and involvement!

pblottiere commented 7 years ago

@dstenger

Once the following tests deactivated in getmap.xml, my report is well generated:

Do you have some news about this issue?

dstenger commented 7 years ago

Thank you for the information.

I tried to start the environment with Docker. So far, everything works fine, but the applications are not started after having executed the above documented commands. Do I have to start them manually?

If it can be confirmed that your issue is the same as in #28, I will close this issue and continue working in #28 (to avoid duplicated documentation).

lgoltz commented 7 years ago

I've the same problem as Dirk described in https://github.com/opengeospatial/ets-wms13/issues/45#issuecomment-294848450

Can you provide the session logs of the test executed in https://github.com/opengeospatial/ets-wms13/issues/45#issuecomment-288337460?

pblottiere commented 7 years ago

@dstenger @lgoltz

I tried to start the environment with Docker. So far, everything works fine, but the applications are not started after having executed the above documented commands. Do I have to start them manually?

It's odd... I tried the previous procedure step by step with a clean docker pull and everything is working fine on my side. Did you start the container with parameters as described in the comment? As a reminder:

$ docker run --cap-add=SYS_ADMIN -v /sys/fs/cgroup:/sys/fs/cgroup -d oslandia/qgis-server-ogc-cite

Once connected to the container, the top command indicates that everything is running (nginx, qgis-server, java and so on):

root@a59b1ab4bb37:/# export TERM=xterm
root@a59b1ab4bb37:/# top
%Cpu(s):  7.8 us,  5.5 sy,  0.0 ni, 66.6 id, 19.9 wa,  0.0 hi,  0.3 si,  0.0 st
KiB Mem :  7855720 total,   140520 free,  4135716 used,  3579484 buff/cache
KiB Swap:  9765884 total,  6628432 free,  3137452 used.  2720448 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                   
  228 root      20   0   38308   3504   3024 R   0.3  0.0   0:00.02 top                       
    1 root      20   0   37068   5140   3988 S   0.0  0.1   0:00.05 systemd                   
   19 root      20   0   35276   4384   4092 S   0.0  0.1   0:00.12 systemd-journal           
   46 root      20   0   20100   1220   1056 S   0.0  0.0   0:00.00 systemd-logind            
   48 root      20   0    4508    760    680 S   0.0  0.0   0:00.00 wrapper_qgisser           
   51 root      20   0    4508   1716   1604 S   0.0  0.0   0:00.00 xvfb-run                  
   54 message+  20   0   42900   3808   3400 S   0.0  0.0   0:00.00 dbus-daemon               
   78 root      20   0  206248  31324  24208 S   0.0  0.4   0:00.12 Xvfb                      
   94 root      20   0 5273460 909312  19752 S   0.0 11.6   0:58.97 java                               
  108 www-data  20   0  125344   3104   1504 S   0.0  0.0   0:00.00 nginx                           
  156 root      20   0 1039156 154188 114404 S   0.0  2.0   0:03.37 qgis_mapserv.fc       
...
...
...

Can you provide the session logs of the test executed in #45 (comment)?

The log file : catalina.txt

Thank you!

lgoltz commented 7 years ago

I've tried again, but without success:

lyn@lg:~$ docker pull oslandia/qgis-server-ogc-cite
Using default tag: latest
latest: Pulling from oslandia/qgis-server-ogc-cite
b3e1c725a85f: Pull complete 
4daad8bdde31: Pull complete 
63fe8c0068a8: Pull complete 
4a70713c436f: Pull complete 
bd842a2105a8: Pull complete 
7f67baa4bf83: Pull complete 
72dc8d8f7299: Pull complete 
d315fa9ce75d: Pull complete 
1bc59329ba85: Pull complete 
Digest: sha256:acaa8e7e12ce69f813dc1cbd1070c200695cdc71fc595a5403a87b3fae2a138b
Status: Downloaded newer image for oslandia/qgis-server-ogc-cite:latest
lyn@lg:~$ docker run --cap-add=SYS_ADMIN -v /sys/fs/cgroup:/sys/fs/cgroup -d oslandia/qgis-server-ogc-cite
ca61d20401e4cc401fb9fe57a3ba8a1948c7ecf1a8c39f368e9ebb2b428e7744
lyn@lg:~$ docker ps -a
CONTAINER ID        IMAGE                                    COMMAND                  CREATED             STATUS                   PORTS               NAMES
ca61d20401e4        oslandia/qgis-server-ogc-cite            "/bin/systemd"           50 seconds ago      Up 49 seconds                                stupefied_knuth
lyn@lg:~$ docker exec -it stupefied_knuth bash
root@ca61d20401e4:/# export TERM=xterm
root@ca61d20401e4:/# top

top - 07:29:09 up  3:26,  0 users,  load average: 0.10, 0.31, 0.42
Tasks:   3 total,   1 running,   2 sleeping,   0 stopped,   0 zombie
%Cpu(s):  6.0 us,  2.1 sy,  0.0 ni, 91.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  7718020 total,  1278172 free,  4051236 used,  2388612 buff/cache
KiB Swap:  7924732 total,  7768816 free,   155916 used.  2868328 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
    1 root      20   0   36536   1948   1512 S   0.0  0.0   0:00.01 systemd
    7 root      20   0   19908   3740   3276 S   0.0  0.0   0:00.01 bash
   24 root      20   0   38308   3568   3068 R   0.0  0.0   0:00.00 top

The catalina log helps only if you provide the log file of the test session, too. At least the file referenced in the catalina log is required:

[Fatal Error] log.xml:42:33: An invalid XML character (Unicode: 0x10) was found in the element content of the document:

[Fatal Error] report_logs.xml:1:9704: Error attempting to parse XML file (href='/srv/tomcat/teamengine/temp/c8891805-b9ef-40fb-bd22-ad184a92ff30/d1e17333_1/d1e17415_1/d1e3456_1/d1e3506_1/log.xml').
pblottiere commented 7 years ago

I've tried again, but without success

OK. Maybe a docker version issue... : 

$ docker --version
Docker version 1.12.1, build 23cf638

The catalina log helps only if you provide the log file of the test session, too. At least the file referenced in the catalina log is required

Here is the corresponding log file: log.txt

lgoltz commented 7 years ago

The log file contains an image where a xml entity or string is expected. The concerned test bbox-miny-gt-maxy expects a ServletException as response to a GetMap request, instead an image is returned.

This is already described in #28.

dstenger commented 7 years ago

28 is reopened and the issue will be discussed and solved there.

dstenger commented 7 years ago

28 was solved. Please see https://github.com/opengeospatial/ets-wms13/issues/28#issuecomment-307120012