[Geoserver-users] GWC seeding: Error rendering coverage on the fast path

Hi,

Yes, I can repeat the error. At one certain zoom level requests to get some tiles always fail. The error at Geotools dev level is:

16 touko 11:25:35 ERROR [org.geowebcache.GeoWebCacheDispatcher] - Problem communicating with GeoServ
er http://localhost:8080/geoserver/gwc/service/wms

Here comes all that appears into the log when panning a bit at that zoom level. It is quite a lot, normal Geoserver users can stop reading here.

-Jukka Rahkonen-

2014-05-16 11:30:55,468 INFO [org.geoserver.wms] -
Request: getServiceInfo
2014-05-16 11:30:55,472 DEBUG [org.geotools.gce.imagemosaic] - Reading mosaic from file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/os.shp
2014-05-16 11:30:55,472 DEBUG [org.geotools.gce.imagemosaic] - Highest res 5.0 5.0
2014-05-16 11:30:55,473 TRACE [org.geotools.gce.imagemosaic] - Adjusted Requested Envelope = ReferencedEnvelope[-2.116241455078125 : -1.926727294921875, 54.133758544921875 : 54.499053955078125]
Requested raster dimension = java.awt.Rectangle[x=-10,y=-10,width=276,height=532]
Corresponding raster source region = java.awt.Rectangle[x=-10,y=-10,width=276,height=532]
2014-05-16 11:30:55,473 DEBUG [org.geotools.gce.imagemosaic] - Loading level 0 with subsampling factors 8 15
2014-05-16 11:30:55,474 DEBUG [org.geotools.gce.imagemosaic] - Prepping to manage SortBy Clause
2014-05-16 11:30:55,474 DEBUG [org.geotools.gce.imagemosaic.catalog] - Index Loaded
2014-05-16 11:30:55,474 DEBUG [org.geotools.data.shapefile] - Read lock: file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/os.qix by ShapefileDataStore-os
2014-05-16 11:30:55,475 DEBUG [org.geotools.data.shapefile] - Read lock: file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/os.shp by ShapefileDataStore-os
2014-05-16 11:30:55,475 DEBUG [org.geotools.data.shapefile] - Read lock: file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/os.shp by ShapefileDataStore-os
2014-05-16 11:30:55,475 DEBUG [org.geotools.data.shapefile] - Read lock: file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/os.qix by ShapefileDataStore-os
2014-05-16 11:30:55,475 DEBUG [org.geotools.data.shapefile] - Read lock: file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/os.qix by ShapefileDataStore-os
2014-05-16 11:30:55,482 DEBUG [org.geotools.data.shapefile] - Read lock: file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/os.qix by ShapefileDataStore-os
2014-05-16 11:30:55,482 DEBUG [org.geotools.data.shapefile] - Read lock: file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/os.qix by ShapefileDataStore-os
2014-05-16 11:30:55,482 TRACE [org.geotools.data.shapefile] - IndexFile has been opened. Number open: 1
2014-05-16 11:30:55,483 DEBUG [org.geotools.data.shapefile] - Read lock: file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/os.shx by org.geotools.data.shapefile.shp.IndexFile
2014-05-16 11:30:55,483 TRACE [org.geotools.data.shapefile] - Reading from file...
2014-05-16 11:30:55,483 TRACE [org.geotools.index.quadtree] - QuadTree opened
2014-05-16 11:30:55,483 DEBUG [org.geotools.data.shapefile] - Read lock: file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/os.qix by ShapefileDataStore-os
2014-05-16 11:30:55,484 TRACE [org.geotools.data.shapefile] - Filling buffer...
2014-05-16 11:30:55,484 DEBUG [org.geotools.data.shapefile] - Read lock: file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/os.shp by org.geotools.data.shapefile.shp.ShapefileReader
2014-05-16 11:30:55,484 TRACE [org.geotools.data.shapefile] - Shapefile Reader has been opened. Number open: 1
2014-05-16 11:30:55,484 DEBUG [org.geotools.data.shapefile] - Read lock: file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/os.dbf by org.geotools.data.shapefile.dbf.IndexedDbaseFileReader
2014-05-16 11:30:55,486 TRACE [org.geotools.data.shapefile] - Dbase File Reader has been opened. Number open: 1
2014-05-16 11:30:55,488 DEBUG [org.geotools.gce.imagemosaic] - Thread:btpool0-2 Loading raster data for granuleDescriptor Description of a granuleDescriptor
BBOX: ReferencedEnvelope[380000.0 : 400000.0, 460000.0 : 480000.0]
file: file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/sd86.tif
gridToWorld: PARAM_MT["Affine",
  PARAMETER["num_row", 3],
  PARAMETER["num_col", 3],
  PARAMETER["elt_0_0", 5.0],
  PARAMETER["elt_0_2", 380002.5],
  PARAMETER["elt_1_1", -5.0],
  PARAMETER["elt_1_2", 479997.5]]
Description of level 2
Description of a granuleDescriptor level
width: 4000
height: 4000
scaleX: 1.0
scaleY: 1.0
baseToLevelTransform: PARAM_MT["Affine",
  PARAMETER["num_row", 3],
  PARAMETER["num_col", 3]]
gridToWorldTransform: PARAM_MT["Affine",
  PARAMETER["num_row", 3],
  PARAMETER["num_col", 3],
  PARAMETER["elt_0_0", 5.0],
  PARAMETER["elt_0_2", 380000.0],
  PARAMETER["elt_1_1", -5.0],
  PARAMETER["elt_1_2", 480000.0]]

2014-05-16 11:30:55,507 DEBUG [org.geotools.gce.imagemosaic] - Loading level 0 with source region: java.awt.Rectangle[x=2498,y=0,width=1502,height=1827] subsampling: 8,15 for granule:file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/sd86.tif
2014-05-16 11:30:55,515 DEBUG [org.geotools.gce.imagemosaic] - We added the granule Description of a granuleDescriptor
BBOX: ReferencedEnvelope[380000.0 : 400000.0, 460000.0 : 480000.0]
file: file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/sd86.tif
gridToWorld: PARAM_MT["Affine",
  PARAMETER["num_row", 3],
  PARAMETER["num_col", 3],
  PARAMETER["elt_0_0", 5.0],
  PARAMETER["elt_0_2", 380002.5],
  PARAMETER["elt_1_1", -5.0],
  PARAMETER["elt_1_2", 479997.5]]
Description of level 2
Description of a granuleDescriptor level
width: 4000
height: 4000
scaleX: 1.0
scaleY: 1.0
baseToLevelTransform: PARAM_MT["Affine",
  PARAMETER["num_row", 3],
  PARAMETER["num_col", 3]]
gridToWorldTransform: PARAM_MT["Affine",
  PARAMETER["num_row", 3],
  PARAMETER["num_col", 3],
  PARAMETER["elt_0_0", 5.0],
  PARAMETER["elt_0_2", 380000.0],
  PARAMETER["elt_1_1", -5.0],
  PARAMETER["elt_1_2", 480000.0]]

2014-05-16 11:30:55,531 DEBUG [org.geotools.gce.imagemosaic] - Thread:btpool0-2 Loading raster data for granuleDescriptor Description of a granuleDescriptor
BBOX: ReferencedEnvelope[380000.0 : 400000.0, 480000.0 : 500000.0]
file: file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/sd88.tif
gridToWorld: PARAM_MT["Affine",
  PARAMETER["num_row", 3],
  PARAMETER["num_col", 3],
  PARAMETER["elt_0_0", 5.0],
  PARAMETER["elt_0_2", 380002.5],
  PARAMETER["elt_1_1", -5.0],
  PARAMETER["elt_1_2", 499997.5]]
Description of level 2
Description of a granuleDescriptor level
width: 4000
height: 4000
scaleX: 1.0
scaleY: 1.0
baseToLevelTransform: PARAM_MT["Affine",
  PARAMETER["num_row", 3],
  PARAMETER["num_col", 3]]
gridToWorldTransform: PARAM_MT["Affine",
  PARAMETER["num_row", 3],
  PARAMETER["num_col", 3],
  PARAMETER["elt_0_0", 5.0],
  PARAMETER["elt_0_2", 380000.0],
  PARAMETER["elt_1_1", -5.0],
  PARAMETER["elt_1_2", 500000.0]]

2014-05-16 11:30:55,546 DEBUG [org.geotools.gce.imagemosaic] - Loading level 0 with source region: java.awt.Rectangle[x=2498,y=0,width=1502,height=4000] subsampling: 8,15 for granule:file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/sd88.tif
2014-05-16 11:30:55,548 DEBUG [org.geotools.gce.imagemosaic] - We added the granule Description of a granuleDescriptor
BBOX: ReferencedEnvelope[380000.0 : 400000.0, 480000.0 : 500000.0]
file: file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/sd88.tif
gridToWorld: PARAM_MT["Affine",
  PARAMETER["num_row", 3],
  PARAMETER["num_col", 3],
  PARAMETER["elt_0_0", 5.0],
  PARAMETER["elt_0_2", 380002.5],
  PARAMETER["elt_1_1", -5.0],
  PARAMETER["elt_1_2", 499997.5]]
Description of level 2
Description of a granuleDescriptor level
width: 4000
height: 4000
scaleX: 1.0
scaleY: 1.0
baseToLevelTransform: PARAM_MT["Affine",
  PARAMETER["num_row", 3],
  PARAMETER["num_col", 3]]
gridToWorldTransform: PARAM_MT["Affine",
  PARAMETER["num_row", 3],
  PARAMETER["num_col", 3],
  PARAMETER["elt_0_0", 5.0],
  PARAMETER["elt_0_2", 380000.0],
  PARAMETER["elt_1_1", -5.0],
  PARAMETER["elt_1_2", 500000.0]]

2014-05-16 11:30:55,569 DEBUG [org.geotools.data.shapefile] - Read lock: file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/os.shp by org.geotools.data.shapefile.shp.ShapefileReader
2014-05-16 11:30:55,570 TRACE [org.geotools.data.shapefile] - Shapefile Reader has been closed. Number open: 0
2014-05-16 11:30:55,570 DEBUG [org.geotools.data.shapefile] - Read lock: file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/os.dbf by org.geotools.data.shapefile.dbf.IndexedDbaseFileReader
2014-05-16 11:30:55,570 TRACE [org.geotools.data.shapefile] - Dbase File Reader has been closed. Number open: 0
2014-05-16 11:30:55,574 DEBUG [org.geotools.data.shapefile] - Read lock: file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/os.shx by org.geotools.data.shapefile.shp.IndexFile
2014-05-16 11:30:55,575 TRACE [org.geotools.data.shapefile] - IndexFile has been closed. Number open: 0
2014-05-16 11:30:55,575 DEBUG [org.geotools.gce.imagemosaic] - Producing the final mosaic, step 1, loop through granule collectors
2014-05-16 11:30:55,575 DEBUG [org.geotools.gce.imagemosaic] - Using collector with filter:Filter.INCLUDE
2014-05-16 11:30:55,575 DEBUG [org.geotools.gce.imagemosaic] - Adding to mosaic granule file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/sd86.tif
2014-05-16 11:30:55,580 DEBUG [org.geotools.gce.imagemosaic] - Adding to mosaic granule file:/C:/ohjelmat/geoserver-2.5/data_dir/coverages/os/sd88.tif
2014-05-16 11:30:55,581 DEBUG [org.geotools.gce.imagemosaic] - Producing the final mosaic, step 2, final mosaicking
2014-05-16 11:30:55,581 DEBUG [org.geotools.gce.imagemosaic] - Loaded bbox ReferencedEnvelope[392502.3509128262 : 400000.0, 470879.3738782472 : 500000.0] while crop bbox ReferencedEnvelope[392502.3509128262 : 400000.0, 470879.3738782472 : 500000.0]
2014-05-16 11:30:55,582 DEBUG [org.geotools.rendering] - Drawing coverage GridCoverage2D["os", GeneralEnvelope[(392480.0, 470825.0), (400000.0, 500000.0)], DefaultProjectedCRS["OSGB 1936 / British National Grid"]]
? RenderedSampleDimension("PALETTE_INDEX":[0.0 ... 0.0])
? ? Category("No data":[0.0 ... 0.0])
? Image=RenderedOp["Mosaic"]

2014-05-16 11:30:55,586 DEBUG [org.geotools.rendering] - Transforming coverage envelope with transform CONCAT_MT[PARAM_MT["Ellipsoid_To_Geocentric",
    PARAMETER["dim", 2],
    PARAMETER["semi_major", 6378137.0],
    PARAMETER["semi_minor", 6356752.314245179]],
  PARAM_MT["Affine",
    PARAMETER["num_row", 4],
    PARAMETER["num_col", 4],
    PARAMETER["elt_0_0", 1.0000204894017095],
    PARAMETER["elt_0_1", 0.00000408221570622301],
    PARAMETER["elt_0_2", -0.00000119751135951892],
    PARAMETER["elt_0_3", -446.4559874115357],
    PARAMETER["elt_1_0", -0.00000408221396450902],
    PARAMETER["elt_1_1", 1.0000204894026148],
    PARAMETER["elt_1_2", 0.00000072724031038791],
    PARAMETER["elt_1_3", 125.16099268054043],
    PARAMETER["elt_2_0", 0.00000119751729685972],
    PARAMETER["elt_2_1", -0.00000072723053356672],
    PARAMETER["elt_2_2", 1.0000204894178448],
    PARAMETER["elt_2_3", -542.0717321410309]],
  PARAM_MT["Geocentric_To_Ellipsoid",
    PARAMETER["dim", 2],
    PARAMETER["semi_major", 6377563.396],
    PARAMETER["semi_minor", 6356256.909237285]],
  PARAM_MT["Transverse_Mercator",
    PARAMETER["semi_major", 6377563.396],
    PARAMETER["semi_minor", 6356256.909237285],
    PARAMETER["central_meridian", -2.0],
    PARAMETER["latitude_of_origin", 49.0],
    PARAMETER["scale_factor", 0.9996012717],
    PARAMETER["false_easting", 400000.0],
    PARAMETER["false_northing", -100000.0]]]
2014-05-16 11:30:55,606 DEBUG [org.geotools.rendering] - Using interpolation javax.media.jai.InterpolationNearest@anonymised.com
2014-05-16 11:30:55,607 INFO [org.geotools.coverage.grid] - Creates a photographic view of grid coverage "os" using operation "Lookup".
2014-05-16 11:30:55,666 DEBUG [org.geotools.referencing.operation.transform] - Optimizing the warp into an affine transformation: AffineTransform[[1.000095176089504, -0.003124210591123, -0.02940741176451], [4.51658864459E-4, 1.00021551847149, -0.225930422037272]]
2014-05-16 11:30:55,667 DEBUG [org.geotools.coverage.processing] - Resampled coverage "os" from coordinate system "OSGB 1936 / British National Grid" (for an image of size 188×389) to coordinate system "WGS 84" (image size 188×389). JAI operation is "Warp" with "Nearest" interpolation on geophysics pixels values. Background value is (0).
2014-05-16 11:30:55,668 DEBUG [org.geotools.rendering] - Reprojecting to crs GEOGCS["WGS 84",
  DATUM["World Geodetic System 1984",
    SPHEROID["WGS 84", 6378137.0, 298.257223563, AUTHORITY["EPSG","7030"]],
    AUTHORITY["EPSG","6326"]],
  PRIMEM["Greenwich", 0.0, AUTHORITY["EPSG","8901"]],
  UNIT["degree", 0.017453292519943295],
  AXIS["Geodetic longitude", EAST],
  AXIS["Geodetic latitude", NORTH],
  AUTHORITY["EPSG","4326"]]
2014-05-16 11:30:55,670 DEBUG [org.geotools.rendering] - Raster Symbolizer
2014-05-16 11:30:55,670 DEBUG [org.geotools.rendering] - Raster Symbolizer
2014-05-16 11:30:55,673 INFO [org.geoserver.wms] -
Request: getMap
  Time =
  Buffer = 0
  Filter = null
  Filters = null
  Width = 256
  Format = image/png
  BgColor = java.awt.Color[r=255,g=255,b=255]
  Crs = GEOGCS["WGS 84",
  DATUM["World Geodetic System 1984",
    SPHEROID["WGS 84", 6378137.0, 298.257223563, AUTHORITY["EPSG","7030"]],
    AUTHORITY["EPSG","6326"]],
  PRIMEM["Greenwich", 0.0, AUTHORITY["EPSG","8901"]],
  UNIT["degree", 0.017453292519943295],
  AXIS["Geodetic longitude", EAST],
  AXIS["Geodetic latitude", NORTH],
  AUTHORITY["EPSG","4326"]]
  Bbox = SRSEnvelope[-2.109375 : -1.93359375, 54.140625 : 54.4921875]
  Env = {}
  Angle = 0.0
  CQLFilter = null
  Elevation =
  FeatureId = null
  FeatureVersion = null
  SRS = EPSG:4326
  SldBody = null
  Sld = null
  Tiled = false
  TilesOrigin = null
  Layers = [org.geoserver.wms.MapLayerInfo@anonymised.com]
  Styles = [StyleImpl[ name=raster]]
  RemoteOwsType = null
  RemoteOwsURL = null
  FormatOptions = {}
  StartIndex = null
  ViewParams = null
  Height = 512
  MaxFeatures = null
  Palette = null
  Transparent = true
  ValidateSchema = false
  SldVersion = null
  Exceptions = SE_XML
  Request = GetMap
  Version = 1.1.1
  Get = true
  BaseUrl = http://localhost:8080/geoserver/
  RawKvp = {BBOX=-2.109375,54.140625,-1.93359375,54.4921875, SERVICE=WMS, HEIGHT=512, REQUEST=GetMap, STYLES=raster, WIDTH=256, EXCEPTIONS=SE_XML, TRANSPARENT=true, VERSION=1.1.1, FORMAT=image/png, GWC_SEED_INTERCEPT=true, LAYERS=topp:os, SRS=EPSG:4326}
  RequestCharset = UTF-8
2014-05-16 11:30:55,686 ERROR [org.geowebcache.GeoWebCacheDispatcher] - Problem communicating with GeoServer http://localhost:8080/geoserver/gwc/service/wms

-----Alkuperäinen viesti-----
Lähettäjä: Tom Chadwin [mailto:tom.chadwin@anonymised.com]
Lähetetty: 16. toukokuuta 2014 11:03
Vastaanottaja: geoserver-users@lists.sourceforge.net
Aihe: Re: [Geoserver-users] GWC seeding: Error rendering coverage on the fast
path

Has anyone been able to recreate the problem using the two TIFFs I linked to?

--
View this message in context: http://osgeo-org.1560.x6.nabble.com/Error-
rendering-coverage-on-the-fast-path-tp5138864p5140671.html
Sent from the GeoServer - User mailing list archive at Nabble.com.

------------------------------------------------------------------------------
"Accelerate Dev Cycles with Automated Cross-Browser Testing - For FREE
Instantly run your Selenium tests across 300+ browser/OS combos.
Get unparalleled scalability from the best Selenium testing platform available
Simple to use. Nothing to install. Get started now for free."
http://p.sf.net/sfu/SauceLabs
_______________________________________________
Geoserver-users mailing list
Geoserver-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/geoserver-users

Thanks, Jukka. It's good to know it was not just caused by some
misconfiguration by me.

Can anyone shed any light on the log Jukka has posted?

Thanks

Tom

--
View this message in context: http://osgeo-org.1560.x6.nabble.com/Re-GWC-seeding-Error-rendering-coverage-on-the-fast-path-tp5140684p5140713.html
Sent from the GeoServer - User mailing list archive at Nabble.com.

On Fri, May 16, 2014 at 10:37 AM, Rahkonen Jukka (Tike) <
jukka.rahkonen@anonymised.com> wrote:

Hi,

Yes, I can repeat the error. At one certain zoom level requests to get
some tiles always fail. The error at Geotools dev level is:

16 touko 11:25:35 ERROR [org.geowebcache.GeoWebCacheDispatcher] - Problem
communicating with GeoServ
er http://localhost:8080/geoserver/gwc/service/wms

Here comes all that appears into the log when panning a bit at that zoom
level. It is quite a lot, normal Geoserver users can stop reading here.

I've just tried using the development version, making both direct wms calls
and gwc ones in 4326 and 900913, png and jpeg... I'm getting no errors.
Then I've tried with the current 2.5.x series, and again, nothing.

Looking at Jukka's log I've reconstructed this GetMap which should
apparently fail, but it does not for me, I just get a blank output:
http://localhost:8080/geoserver/wms?BBOX=-2.109375,54.140625,-1.93359375,54.4921875&SERVICE=WMS&HEIGHT=512&REQUEST=GetMap&STYLES=raster&WIDTH=256&EXCEPTIONS=SE_XML&TRANSPARENT=true&VERSION=1.1.1&FORMAT=image/png&GWC_SEED_INTERCEPT=true&LAYERS=mosaicError&SRS=EPSG:4326

I likely have lost something along the 50 messages in this thread.
Jukka, which version of GeoServer were you trying, using which JDK and so
on?

Cheers
Andrea

--

Meet us at GEO Business 2014! in London! Visit http://goo.gl/fES3aK
for more information.

Ing. Andrea Aime
@geowolf
Technical Lead

GeoSolutions S.A.S.
Via Poggio alle Viti 1187
55054 Massarosa (LU)
Italy
phone: +39 0584 962313
fax: +39 0584 1660272
mob: +39 339 8844549

http://www.geo-solutions.it
http://twitter.com/geosolutions_it

-------------------------------------------------------