[udig-devel] Something strange with map rendering
Jesse Eichar
jeichar at refractions.net
Sun Jan 7 12:20:30 PST 2007
Good research thanks for that Andrea. I think the issue is that the
RenderManager controls when the display is updated (which is ever 1
second). I should be able to fix this issue by updating the screen
when the data is finished being render irregardless of whether the 1
second has been reached.
Jesse
On 7-Jan-07, at 5:39 AM, Andrea Aime wrote:
> Andrea Aime ha scritto:
>> Hi,
>> today I was fiddling a little with uDig and, well... there is
>> something
>> strange I keep on seeing during map rendering from old versions to
>> now.
>> I have the strong impression the actual rendering process does not
>> start when I release the mouse after a zoom or a pan, but some
>> 0.2-0.3
>> second after that, adding to the perception the UI is slow.
>> Maybe it's the Eclipse job system that does not start the rendering
>> job right away, or maybe it's just an impression, but yet, it's funny
>> to see the CPU load totally to zero for such a long time... it's
>> rendering a map, I would expect it to use actual CPU, and see the
>> load
>> right away...
>
> Ok, did a little investigation and found that on a simple map uDig
> throws aways 2/3 to 4/5 of the actual time used to display the
> resulting image in some kind of waits.
>
> I've used the StopWatch class attached to get timings, and applied
> the attached patch to the other classes (I could not get svn to
> generate a diff with StopWatch.java included, complains about some
> non ASCII char, don't know...).
> The class is really scripty, as the method I used to gather timings.
> Time gathering works by resetting the timer when the mouse is released
> (so it'll works just for zoom and pan), and then printing the
> elapsed time in selected places in the code.
>
> I'm using a single postgis layer (whole world contries, 6MB .shp
> when converted as a shapefile) have a look at what happens:
>
> (zooming in using window)
> [EventJob] Mouse released - Stopwatch reset at 1168175951828
> [CompositeRendererJob] run started: 515
> [RenderExecutorImpl] scheduling render job: 515
> [RenderJob] run started: 515
> [BasicFeatureRenderer] prepare: 515
> [BasicFeatureRenderer] start rendering: 547
> [BasicFeatureRenderer] rendering ended: 797
> [RenderJob] run terminated: 797
> [CompositeRendererJob] run terminated: 1218
> (the following is image conversion between RenderedImage and swt
> image)
> [ViewportPaneSWT] create image, before: 1218
> [ViewportPaneSWT] create image, after: 1218
>
> (panning)
> [EventJob] Mouse released - Stopwatch reset at 1168175989343
> [CompositeRendererJob] run started: 500
> [RenderExecutorImpl] scheduling render job: 500
> [RenderJob] run started: 500
> [BasicFeatureRenderer] prepare: 516
> [BasicFeatureRenderer] start rendering: 547
> [BasicFeatureRenderer] rendering ended: 813
> [RenderJob] run terminated: 813
> [CompositeRendererJob] run terminated: 1203
> [ViewportPaneSWT] create image, before: 1203
> [ViewportPaneSWT] create image, after: 1203
>
> (zooming in in a very small area, some ten Greek islands)
> [EventJob] Mouse released - Stopwatch reset at 1168176024968
> [CompositeRendererJob] run started: 500
> [RenderExecutorImpl] scheduling render job: 500
> [RenderJob] run started: 500
> [BasicFeatureRenderer] prepare: 500
> [BasicFeatureRenderer] start rendering: 532
> [BasicFeatureRenderer] rendering ended: 719
> [RenderJob] run terminated: 719
> [CompositeRendererJob] run terminated: 1203
> [ViewportPaneSWT] create image, before: 1203
> [ViewportPaneSWT] create image, after: 1203
>
> Well, in both you can see actual rendering takes no more than 400ms
> on the whole image (world countries) and less than 200ms in the very
> zoomed in case, yet the total time is basically unchanged, 1.2
> seconds.
> First we can see rendering is started 500ms after the command, and
> then
> that composite render closes the rendering cycle always after 700ms
> from
> when it was started... in the worst case, uDig is spending 1second (an
> eternity in my book) doing nothing, no wonder I can't see the cpu
> usage go up.
>
> To give you a user level comparison, asking the same layer to
> Geoserver from a browser using:
> http://localhost:8080/geoserver/wms?
> bbox=-180,-90,180,90&styles=&Format=image/
> png&request=GetMap&layers=topp:world&width=500&height=250&srs=EPSG:
> 4326
> (same image size as the one I used in uDig, I used a quite small
> udig window)
> takes 0.8 seconds (FasterFox timings). Not only it's faster, but
> consider Geoserver has to encode the image into png, and the
> browser has to decode it, whilst uDig does not have to perform such
> work.
>
> I haven't investigated further, yet I would urge uDig developers
> to put some thoughts and identify why that much valuable time is
> thrown away. Oh, the patches are against 1.1.x branch.
>
> Cheers
> Andrea
>
>
> package net.refractions.udig.project;
>
> /**
> * A simple utility class to add timed printlns in an algorithm
> *
> * @author aaime
> *
> */
> public class StopWatch {
> static long start;
>
> public static void reset(Object context, String msg) {
> System.out.println();
> System.out.println();
> start = System.currentTimeMillis();
>
> System.out.print("[" + context.getClass().getSimpleName() +
> "] " + msg
> + " - ");
> System.out.println("Stopwatch reset at " + start);
> }
>
> protected static void mark(String msg) {
> long elapsed = System.currentTimeMillis() - start;
> System.out.println(msg + ":\t" + elapsed);
> }
>
> public static void mark(Object context, String msg) {
> mark("[" + context.getClass().getSimpleName() + "] " + msg);
> }
> }
> Index: net.refractions.udig.libs/.classpath
> ===================================================================
> --- net.refractions.udig.libs/.classpath (revisione 23698)
> +++ net.refractions.udig.libs/.classpath (copia locale)
> @@ -1,49 +1,49 @@
> -<?xml version="1.0" encoding="UTF-8"?>
> -<classpath>
> - <classpathentry kind="src" path=""/>
> - <classpathentry exported="true" kind="lib" path="lib/commons-
> collections-2.1.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/commons-
> pool-1.2.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/commons-
> codec-1.3.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/geoapi-2.0-
> tiger.jar" sourcepath="/Users/Jesse/Development/GeoAPI-2_0_0/
> sources"/>
> - <classpathentry exported="true" kind="lib" path="lib/
> log4j-1.2.8.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/opengis-
> legacy-0.1.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/
> units-0.01.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/wkb4j-1.0-
> RC1.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/
> xmlrpc-2.0.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/
> hsqldb-1.8.0.1.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/
> xerces-2.4.0.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/commons-
> lang-2.1.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> api-2.2.x.jar" sourcepath="/gt2-api"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> arcgrid-2.2.x.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> brewer-2.2.x.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> coverage-2.2.x.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> db2-2.2.x.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-epsg-
> wkt-2.2.x.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> geotiff-2.2.x.jar" sourcepath="/Users/Jesse/Development/repo/
> geotools/gt2.2.x/plugin/geotiff"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> gml-2.2.x.jar" sourcepath="/Users/Jesse/Development/repo/geotools/
> gt2.2.x/plugin/gml"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> hsql-2.2.x.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> image-2.2.x.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-indexed-
> shapefile-2.2.x.jar" sourcepath="/gt2-indexed-shapefile"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> main-2.2.x.jar" sourcepath="/gt2-main"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> mysql-2.2.x.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-oracle-
> spatial-2.2.x.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> postgis-2.2.x.jar" sourcepath="/gt2-postgis"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> referencing-2.2.x.jar" sourcepath="/gt2-referencing"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> render-2.2.x.jar" sourcepath="/gt2-render"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> shapefile-2.2.x.jar" sourcepath="/gt2-shapefile"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> shapefile-renderer-2.2.x.jar" sourcepath="/gt2-shapefile-renderer"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> validation-2.2.x.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> wfs-2.2.x.jar" sourcepath="/gt2-wfs"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> wms-2.2.x.jar" sourcepath="/gt2-wms"/>
> - <classpathentry exported="true" kind="lib" path="lib/jdom-1.0.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/mysql-
> connector-java-3.0.10.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/
> vecmath-1.3.1.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/
> jts-1.7.1.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/
> spatialdb-0.1.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/
> picocontainer-1.2.jar"/>
> - <classpathentry exported="true" kind="lib" path="lib/gt2-
> arcsde-2.2.x.jar" sourcepath="C:/java/gt2.2.x/plugin/arcsde"/>
> - <classpathentry exported="true" kind="lib" path="lib/
> concurrent-1.3.4.jar"/>
> - <classpathentry kind="con"
> path="org.eclipse.jdt.launching.JRE_CONTAINER"/>
> - <classpathentry kind="con"
> path="org.eclipse.pde.core.requiredPlugins"/>
> - <classpathentry kind="output" path="bin"/>
> -</classpath>
> +<?xml version="1.0" encoding="UTF-8"?>
> +<classpath>
> + <classpathentry kind="src" path=""/>
> + <classpathentry exported="true" kind="lib" path="lib/commons-
> codec-1.3.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/geoapi-2.0-
> tiger.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/
> log4j-1.2.8.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/opengis-
> legacy-0.1.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/
> units-0.01.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/wkb4j-1.0-
> RC1.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/
> xmlrpc-2.0.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/
> hsqldb-1.8.0.1.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/
> xerces-2.4.0.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/commons-
> lang-2.1.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> api-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> arcgrid-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> brewer-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> coverage-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> db2-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-epsg-
> wkt-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> geotiff-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> gml-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> hsql-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> image-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-indexed-
> shapefile-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> main-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> mysql-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-oracle-
> spatial-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> postgis-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> referencing-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> render-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> shapefile-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> shapefile-renderer-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> validation-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> wfs-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> wms-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/jdom-1.0.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/mysql-
> connector-java-3.0.10.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/
> vecmath-1.3.1.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/
> jts-1.7.1.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/
> spatialdb-0.1.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/
> picocontainer-1.2.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/gt2-
> arcsde-2.2.x.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/
> concurrent-1.3.4.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/commons-
> pool-1.2.jar"/>
> + <classpathentry exported="true" kind="lib" path="lib/commons-
> collections-2.1.jar"/>
> + <classpathentry kind="con"
> path="org.eclipse.jdt.launching.JRE_CONTAINER"/>
> + <classpathentry kind="con"
> path="org.eclipse.pde.core.requiredPlugins"/>
> + <classpathentry kind="output" path="bin"/>
> +</classpath>
> Index: net.refractions.udig.render.feature.basic/src/net/
> refractions/udig/render/internal/feature/basic/
> BasicFeatureRenderer.java
> ===================================================================
> --- net.refractions.udig.render.feature.basic/src/net/refractions/
> udig/render/internal/feature/basic/BasicFeatureRenderer.java
> (revisione 23698)
> +++ net.refractions.udig.render.feature.basic/src/net/refractions/
> udig/render/internal/feature/basic/BasicFeatureRenderer.java (copia
> locale)
> @@ -20,6 +20,7 @@
>
> import net.refractions.udig.core.TransparencyRemovingVisitor;
> import net.refractions.udig.project.ILayer;
> +import net.refractions.udig.project.StopWatch;
> import net.refractions.udig.project.internal.ProjectPlugin;
> import net.refractions.udig.project.internal.StyleBlackboard;
> import
> net.refractions.udig.project.internal.render.impl.RendererImpl;
> @@ -193,7 +194,7 @@
> @SuppressWarnings("unchecked")
> private void render(Graphics2D graphics, Envelope bounds,
> IProgressMonitor monitor) throws RenderException {
> -
> + StopWatch.mark(this, "prepare");
> getContext().setStatus(ILayer.WAIT);
> getContext().setStatusMessage
> (Messages.BasicFeatureRenderer_rendering_status);
> String endMessage=null;
> @@ -288,7 +289,7 @@
> : RenderingHints.VALUE_ANTIALIAS_OFF);
> if( monitor.isCanceled() )
> return;
> -
> + StopWatch.mark(this, "start rendering");
> renderer2.setJava2DHints(hints);
> renderer2.paint(graphics, paintArea, validBounds);
>
> @@ -330,6 +331,7 @@
> }
> }
> }
> + StopWatch.mark(this, "rendering ended");
> }
>
> protected GTRenderer getRenderer() {
> Index: net.refractions.udig.project/src/net/refractions/udig/
> project/StopWatch.java
> ===================================================================
> --- net.refractions.udig.project/src/net/refractions/udig/project/
> StopWatch.java (revisione 0)
> +++ net.refractions.udig.project/src/net/refractions/udig/project/
> StopWatch.java (revisione 0)
> @@ -0,0 +1,31 @@
> +package net.refractions.udig.project;
> +
> +/**
> + * A simple utility class to add timed printlns in an algorithm
> + *
> + * @author aaime
> + *
> + */
> +public class StopWatch {
> + static long start;
> +
> + public static void reset(Object context, String msg) {
> + System.out.println();
> + System.out.println();
> + start = System.currentTimeMillis();
> +
> + System.out.print("[" + context.getClass().getSimpleName()
> + "] " + msg
> + + " - ");
> + System.out.println("Stopwatch reset at " + start);
> + }
> +
> + protected static void mark(String msg) {
> + long elapsed = System.currentTimeMillis() - start;
> + System.out.println(msg + ":\t" + elapsed);
> + }
> +
> + public static void mark(Object context, String msg) {
> + mark("[" + context.getClass().getSimpleName() + "] " + msg);
> + }
> +
> +}
> _______________________________________________
> User-friendly Desktop Internet GIS (uDig)
> http://udig.refractions.net
> http://lists.refractions.net/mailman/listinfo/udig-devel
More information about the udig-devel
mailing list