Oracle: PHP-Mapscript: Commit bc4ccf09b9450b30a2bfcdbf0fb4ec20cd53fc7c causes loop to be finished too early #4508

Closed
regiodata opened this Issue Oct 22, 2012 · 19 comments

Projects

None yet

5 participants

@regiodata

In our opinion commit bc4ccf0 causes the loop to be finished too early.
We have experienced the problem with php-mapscript (php 5.3.3-7+squeeze14).
With mapserver-6.2.0-beta2 everything worked fine. However with mapserver-6.2.0-beta3 the resulting map image shows a subset of the expected objects.

So we rolled back commit bc4ccf0 and everything worked fine again.

@unicolet
Contributor

Could you submit a small test case?

@unicolet unicolet was assigned Oct 22, 2012
@regiodata
regiodata commented Oct 23, 2012 edited

Thanks for your quick response.
Here’s the mapfile:

MAP
    EXTENT      3396887 5273890 3402258 5277865
    SIZE        537 397
    UNITS       METERS
    FONTSET     "../../global/font/fonts.fnt"
    SYMBOLSET   "./symbol/symbol.sym"
    IMAGECOLOR  255 255 255
    IMAGETYPE   aggpng24
    DEBUG       1

    OUTPUTFORMAT
        NAME        aggpng24
        DRIVER      AGG/PNG
        MIMETYPE    "image/png"
        IMAGEMODE   RGBA
        EXTENSION   "png"
        TRANSPARENT TRUE
    END

    PROJECTION
        "init=epsg:31467"
    END

    LAYER
        NAME            "testcase_objects"
        TYPE            polygon
        STATUS          ON
        CONNECTION      "[DBCONNECT]"
        CONNECTIONTYPE  oraclespatial
        DATA            "geom FROM ([SQL]) USING UNIQUE fid SRID 82027 FILTER"
        UNITS           METERS

        PROJECTION
            "init=epsg:31467"
        END

        CLASS
            NAME        "FLST" 
            STYLE
                COLOR           200 35 35
                OUTLINECOLOR    1 1 1
            END
        END
    END
END

php-mapscript:

$ms_map = ms_newMapObj('[MAP]');
$ms_image = $ms_map->draw();

header('Content-Type: image/png');
$ms_image->saveImage();

Result:

  • Using PHP MapScript (mapserver-6.2.0-beta3) with Commit bc4ccf0 objects are missing.
    mapserver-6 2 0-beta3_php_mapscript_with_bc4ccf09b9450b30a2bfcdbf0fb4ec20cd53fc7c
  • Using CGI MapServer Request (mapserver-6.2.0-beta3) with Commit bc4ccf0 all objects are drawn.
    mapserver-6 2 0-beta3_mapserver_with_bc4ccf09b9450b30a2bfcdbf0fb4ec20cd53fc7c
  • Using PHP MapScript (mapserver-6.2.0-beta3) without Commit bc4ccf0 all objects are drawn.
    mapserver-6 2 0-beta3_php_mapscript_without_bc4ccf09b9450b30a2bfcdbf0fb4ec20cd53fc7c
@unicolet
Contributor

The issue appears only with php mapscript because php mapscript (and only php mapscript) enables pagination by default on the oracle and postgis drivers.
All other mapscripts and mapserver cgi leave it off and thus they do not trigger the bug.

I need you to do one quick test: reapply commit bc4ccf0 and then change line 1678 in maporaclespatial.c:

layerinfo->paging = MS_FALSE;

rebuild and let me know if this fixes things.

We'll also need to get @aboudreault to take a look at this.

@regiodata
regiodata commented Oct 23, 2012 edited

I reapplied commit bc4ccf0 (on mapserver-6.2.0-beta3) and changed line 1678 to

  memset( layerinfo, 0, sizeof(msOracleSpatialLayerInfo) );
  //layerinfo->paging = MS_TRUE;
  layerinfo->paging = MS_FALSE; /*test*/

  msSplitLogin( layer->connection, layer->map, &username, &password, &dblink );

Unfortunately objects are still not drawn. The image looks like the image above:
mapserver-6 2 0-beta3_mapserver_with_bc4ccf09b9450b30a2bfcdbf0fb4ec20cd53fc7c

@tbonfort
Member

@unicolet, when you write "The issue appears only with php mapscript because php mapscript (and only php mapscript) enables pagination by default on the oracle and postgis drivers." where are ypu getting this info from? I don't believe that mapscript itself is at play here, even more so given the php mapscript snippet that was given in this issue.

thomas

@regiodata

Debug output for PHP MapScript:

[Tue Oct 23 11:24:18 2012].272292 msOracleSpatialLayerOpen called with: [SQL] (Layer pointer 0xb8a0f6a0)
[Tue Oct 23 11:24:18 2012].272308 msConnPoolRequest(testcase_objects,xxx/xxx@gisdb) -> got 0xb8c720a0
[Tue Oct 23 11:24:18 2012].275143 msOracleSpatialLayerFreeItemInfo was called.
[Tue Oct 23 11:24:18 2012].275189 msOracleSpatialLayerWhichShapes was called.
[Tue Oct 23 11:24:18 2012].275243 msOracleSpatialLayerWhichShapes. Using this Sql to retrieve the data: [SQL]
[Tue Oct 23 11:24:18 2012].275253 msOracleSpatialLayerWhichShapes. Bind values: srid:82027   minx:3396882.348485   miny:5273890.000000  maxx:3402262.651515   maxy:5277865.000000
[Tue Oct 23 11:24:18 2012].275287 msOracleSpatialLayerWhichShapes getting ordinate definition.
[Tue Oct 23 11:24:18 2012].276027 msOracleSpatialLayerWhichShapes converting to OCIColl.
[Tue Oct 23 11:24:18 2012].276063 msOracleSpatialLayerWhichShapes bind by name and object.
[Tue Oct 23 11:24:18 2012].276080 msOracleSpatialLayerWhichShapes name and object now bound.
[Tue Oct 23 11:24:18 2012].374338 msOracleSpatialLayerFreeItemInfo was called.
[Tue Oct 23 11:24:18 2012].374365 msOracleSpatialLayerClose was called. Layer: 0xb8a0f6a0, Layer name: testcase_objects. Layer connection: xxx/xxx@gisdb
[Tue Oct 23 11:24:18 2012].379164 msOracleSpatialLayerClose. Cleaning layerinfo handlers.
[Tue Oct 23 11:24:18 2012].379242 msOracleSpatialLayerClose. Release the Oracle Pool.
[Tue Oct 23 11:24:18 2012].379252 msConnPoolRelease(testcase_objects,xxx/xxx@gisdb,0xb8c720a0)
[Tue Oct 23 11:24:18 2012].379261 msDrawMap(): Layer 0 (testcase_objects), 0.107s
[Tue Oct 23 11:24:18 2012].379275 msDrawMap(): Drawing Label Cache, 0.000s
[Tue Oct 23 11:24:18 2012].379283 msDrawMap() total time: 0.109s
[Tue Oct 23 11:24:18 2012].398349 msFreeMap(): freeing map at 0xb8dc6bf0.
[Tue Oct 23 11:24:18 2012].398365 msOracleSpatialLayerClose was called. Layer: 0xb8a0f6a0, Layer name: testcase_objects. Layer connection: xxx/xxx@gisdb
[Tue Oct 23 11:28:10 2012].325434 msConnPoolClose(xxx/xxx@gisdb,0xb8c720a0)

Debug output for CGI MapServer:

[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:09 2012].227718
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] msDrawMap(): rendering using outputformat named aggpng24 (AGG/PNG).
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:09 2012].228711
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] msDrawMap(): WMS/WFS set-up and query, 0.000s
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:09 2012].229404
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] msOracleSpatialLayerOpen called with: [SQL] (Layer pointer 0x82baa58)
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:09 2012].273434
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] msOracleSpatialLayerOpen. Shared connection not available. Creating one.
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:09 2012].274192
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] msConnPoolRegister(testcase_objects,xxx/xxx@gisdb,0x82e8790)
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:09 2012].280264
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] msOracleSpatialLayerFreeItemInfo was called.
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:09 2012].280924
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] msOracleSpatialLayerWhichShapes was called.
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:09 2012].281570
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] msOracleSpatialLayerWhichShapes. Using this Sql to retrieve the data: [SQL]
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:09 2012].284079 msOracleSpatialLayerWhichShapes. Bind values: srid:82027   minx:3396882.348485   miny:5273890.000000  maxx:3402262.
651515   maxy:5277865.000000
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:09 2012].284190 msOracleSpatialLayerWhichShapes getting ordinate definition.
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:09 2012].285428 msOracleSpatialLayerWhichShapes converting to OCIColl.
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:09 2012].285609 msOracleSpatialLayerWhichShapes bind by name and object.
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:09 2012].285673 msOracleSpatialLayerWhichShapes name and object now bound.
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:09 2012].489885
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] msOracleSpatialLayerNextShape on layer 0x82baa58, Fetched 1024 more rows (2048 total)
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:09 2012].604971
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] msOracleSpatialLayerNextShape on layer 0x82baa58, Fetched 1024 more rows (3072 total)
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:09 2012].716255
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] msOracleSpatialLayerNextShape on layer 0x82baa58, Fetched 1024 more rows (4096 total)
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:09 2012].819330
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] msOracleSpatialLayerNextShape on layer 0x82baa58, Fetched 1024 more rows (5120 total)
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:09 2012].934839
[Tue Oct 23 11:31:09 2012] [error] [client 192.168.90.80] msOracleSpatialLayerNextShape on layer 0x82baa58, Fetched 1024 more rows (6144 total)
[Tue Oct 23 11:31:10 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:10 2012].58300
[Tue Oct 23 11:31:10 2012] [error] [client 192.168.90.80] msOracleSpatialLayerNextShape on layer 0x82baa58, Fetched 1024 more rows (7168 total)
[Tue Oct 23 11:31:10 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:10 2012].172008
[Tue Oct 23 11:31:10 2012] [error] [client 192.168.90.80] msOracleSpatialLayerNextShape on layer 0x82baa58, Fetched 1024 more rows (8192 total)
[Tue Oct 23 11:31:10 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:10 2012].273146
[Tue Oct 23 11:31:10 2012] [error] [client 192.168.90.80] msOracleSpatialLayerNextShape on layer 0x82baa58, Fetched 1024 more rows (9216 total)
[Tue Oct 23 11:31:10 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:10 2012].385319
[Tue Oct 23 11:31:10 2012] [error] [client 192.168.90.80] msOracleSpatialLayerNextShape on layer 0x82baa58, Fetched 1024 more rows (10240 total)
[Tue Oct 23 11:31:10 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:10 2012].484283
[Tue Oct 23 11:31:10 2012] [error] [client 192.168.90.80] msOracleSpatialLayerNextShape on layer 0x82baa58, Fetched 1024 more rows (11264 total)
[Tue Oct 23 11:31:10 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:10 2012].590766
[Tue Oct 23 11:31:10 2012] [error] [client 192.168.90.80] msOracleSpatialLayerNextShape on layer 0x82baa58, Fetched 1024 more rows (12288 total)
[Tue Oct 23 11:31:10 2012] [error] [client 192.168.90.80] [Tue Oct 23 11:31:10 2012].647353
[Tue Oct 23 11:31:10 2012] [error] [client 192.168.90.80] msOracleSpatialLayerNextShape on layer 0x82baa58, Fetched 104 more rows (12392 total)
[...]

Note "Fetched 1024 more rows" not appearing with mapscript.

@unicolet
Contributor

I know that swig mapscript disables pagination programmatically:

cce80f3

and I don't see the same calls in php mapscript anywhere, hence my
conclusion.
Also I have at least one Oracle+Java mapscript user who did not report any
issue and I have used postgis+python mapscript myself w/o issues very
recently.

I'll be on IRC (on and off, as I'm busy doing other stuff too) if you want
to discuss this further.

Cheers,
Umberto

On Tue, Oct 23, 2012 at 11:30 AM, Thomas Bonfort
notifications@github.comwrote:

@unicolet https://github.com/unicolet, when you write "The issue
appears only with php mapscript because php mapscript (and only php
mapscript) enables pagination by default on the oracle and postgis
drivers." where are ypu getting this info from? I don't believe that
mapscript itself is at play here, even more so given the php mapscript
snippet that was given in this issue.

thomas


Reply to this email directly or view it on GitHubhttps://github.com/mapserver/mapserver/issues/4508#issuecomment-9695795.

@tbonfort
Member

@regiodata given the php logs you posted, it seems you are doing a query before doing a draw. Is the php snippet of code you posted

$ms_map = ms_newMapObj('[MAP]');
$ms_image = $ms_map->draw();

header('Content-Type: image/png');
$ms_image->saveImage();

the exact code that reproduces the issue, or are you doing other things in mapscript before the map->draw() ?

@regiodata

@tbonfort Its exactly the code that produces the issue.

<?php
    $ms_map = ms_newMapObj('[MAP]');
    $ms_image = $ms_map->draw();

    header('Content-Type: image/png');
    $ms_image->saveImage();
?>

However I understand your note. The debug output was corrupted by other MapScript processes on my server. I stopped them all and here's the output:

[Tue Oct 23 13:35:32 2012].47240 msDrawMap(): rendering using outputformat named aggpng24 (AGG/PNG).
[Tue Oct 23 13:35:32 2012].47266 msDrawMap(): WMS/WFS set-up and query, 0.000s
[Tue Oct 23 13:35:32 2012].47282 msOracleSpatialLayerOpen called with: [SQL] (Layer pointer 0xb95d9238)
[Tue Oct 23 13:35:32 2012].81637 msOracleSpatialLayerOpen. Shared connection not available. Creating one.
[Tue Oct 23 13:35:32 2012].81657 msConnPoolRegister(testcase_objects,xxx/xxx@gisdb,0xb91e8928)
[Tue Oct 23 13:35:32 2012].85718 msOracleSpatialLayerFreeItemInfo was called.
[Tue Oct 23 13:35:32 2012].85764 msOracleSpatialLayerWhichShapes was called.
[Tue Oct 23 13:35:32 2012].85823 msOracleSpatialLayerWhichShapes. Using this Sql to retrieve the data: [SQL]
[Tue Oct 23 13:35:32 2012].85833 msOracleSpatialLayerWhichShapes. Bind values: srid:82027   minx:3396882.348485   miny:5273890.000000  maxx:3402262.651515   maxy:5277865.000000
[Tue Oct 23 13:35:32 2012].85872 msOracleSpatialLayerWhichShapes getting ordinate definition.
[Tue Oct 23 13:35:32 2012].86721 msOracleSpatialLayerWhichShapes converting to OCIColl.
[Tue Oct 23 13:35:32 2012].86761 msOracleSpatialLayerWhichShapes bind by name and object.
[Tue Oct 23 13:35:32 2012].86778 msOracleSpatialLayerWhichShapes name and object now bound.
[Tue Oct 23 13:35:32 2012].202691 msOracleSpatialLayerFreeItemInfo was called.
[Tue Oct 23 13:35:32 2012].202718 msOracleSpatialLayerClose was called. Layer: 0xb95d9238, Layer name: testcase_objects. Layer connection: xxx/xxx@gisdb
[Tue Oct 23 13:35:32 2012].207438 msOracleSpatialLayerClose
@unicolet
Contributor

It's taken some time but I was eventually able to reproduce the issue on git master with:

  • shp2img
  • python mapscript
  • java mapscript

whenever mapserver renders an Oracle spatial layer (in my case a layer with a little over 50K features).

Reverting the patch as suggested by @regiodata fixes the issue and I did not find any side effects.

Areas that might need further testing: WxS, querying.

@aboudreault
Member

@unicolet what if you set layer->maxfeature in php? Does it work?

@regiodata

@aboudreault As I first noticed the issue I tried to set layer->maxfeature to a big value. Unfortunately it doesn’t help. On the other hand it worked with small values as expected.

Manuel

@aboudreault
Member

I mean, with the changeset reverted? To see if the maxfeature still works.

@regiodata
regiodata commented Oct 23, 2012 edited

Right now I checked it with mapserver-6.2.0-rc1 without the changeset. layer->maxfeature works, for me, as expected.

For example:

<?php
    $ms_map = ms_newMapObj('[MAP]');

    //maxfeatures-Test
    $ms_layer = $ms_map->getLayerByName('testcase_objects');
    $ms_layer->set('maxfeatures', 4000);

    $ms_image = $ms_map->draw();

    header('Content-Type: image/png');
    $ms_image->saveImage();
?>

Outputs:
mapserver-6 2 0-rc1_php_mapscript_without_bc4ccf09b9450b30a2bfcdbf0fb4ec20cd53fc7c_maxfeatures

Manuel

@regiodata

I just looked at Milestone 6.2 open issues.
Due to the fact that the bug seems to be introduced in mapserver-6.2.0-beta3, this issue should also be assigned to Milestone 6.2?

Manuel

@sdlime
Member
sdlime commented Nov 2, 2012

Yes, it should be a 6.2 issue.


From: Manuel [notifications@github.com]
Sent: Friday, November 02, 2012 3:11 AM
To: mapserver/mapserver
Subject: Re: [mapserver] Oracle: PHP-Mapscript: Commit bc4ccf0 causes loop to be finished too early (#4508)

I just looked at Milestone 6.2 open issues.
Due to the fact that the bug seems to be introduced in mapserver-6.2.0-beta3, this issue should also be assigned to Milestone 6.2?

Manuel


Reply to this email directly or view it on GitHubhttps://github.com/mapserver/mapserver/issues/4508#issuecomment-10007395.

@regiodata

In my opinion I don’t have permission to set the milestone.
@sdlime May you set it please?

@aboudreault
Member

done

@unicolet
Contributor
unicolet commented Nov 6, 2012

Closing: fix committed to master and branch-6-2

@unicolet unicolet closed this Nov 6, 2012
@mkofahl mkofahl pushed a commit to faegi/mapserver that referenced this issue Apr 9, 2013
@unicolet unicolet Rolled back bc4ccf0 to fix pagination loop issue #4508 with oracle sp…
…atial layers
4e7f7fd
@mkofahl mkofahl pushed a commit to faegi/mapserver that referenced this issue Apr 9, 2013
@unicolet unicolet Rolled back bc4ccf0 to fix pagination loop issue #4508 with oracle sp…
…atial layers
d7c86f8
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment