gistfile1.irclog

[09:25] <loomsen> hello everybody. after a couple of weeks of testing different setups (centos, fedora, postgresql 9.1, 9.3, postgis 1.5, 2.0, 2.1) the only acceptable performance I get is with pgsql 9.3 and postgis 1.5. Using postgis 2.X results in query ten times slower than with 1.5. I've tuned postgresql to the max, but still
[09:26] <loomsen> I had to set work_mem to 2GB to stop postgres creating temp files on the disk for each tile, the underlying RAID0 SSD was permanently writing at full speed (when running a select)
[09:27] <loomsen> anyone else had this problems? I don't have any clue what could possibly be wrong, and I'd like to update to postgis 2.1, as the changelog states a lot of performance improvements. yet, I'm experiencing the complete opposite
[09:29] <loomsen> I did the setup using create extension for postgis 2.X, using the imposm-psql tool basically, and imposm for imports
[...]
[15:20] <robe2> loomsen: do you have any explain plans to show the difference in performance?  also which 2.1 are you using -- should be using 2.1.3
[15:40] * zz_flippmoke is now known as flippmoke
[15:48] <loomsen> robe2: i've been trying postgis 2.0.6 and 2.1.3 yes, the most recent ones from the upstream postgresql repos. these are the results for postgis 1.5 (which works acceptably well) and postgis 2.0 (which doesnt) https://gist.github.com/loomsen/990b37f342a2dbd84a93
[15:48] <sigq> Title: postgis 1.5.8 (at gist.github.com)
[15:49] <loomsen> robe2: I dont have a 9.3/postgis 2.1.3 installation at the moment, but it wouldn't take much time to create one (it would take some time for the import though) however, the symptoms and results are roughly the same for 2.X
[15:53] <loomsen> robe2: the real world performance when seeding files is about six to ten times worse for 2.X
[15:53] <robe2> loomsen: hmm you are just doing an ST_SRID check which isn't terribly interesting.  Are your queries that use spatial indexes affected as well?
[15:54] <loomsen> robe2: hmm, how could I check? those queries were the only queries which took more than a second when seeding
[15:54] <robe2> one thought about time difference is that between 1.5 and 2.0 the geometry data type got a bit bigger I think so it is possible ST_SRID is adversely affected.  though it shouldn't be by that much.
[15:55] <robe2> what happens if you take out the  ORDER BY area? 
[15:56] <loomsen> robe2: Total runtime: 6.146 ms  on postgis2, Total runtime: 6.059 ms on 1.5
[15:56] <robe2> loomsen: that is after taking out the ORDER BY ?
[15:56] <loomsen> robe2: yes
[15:58] <robe2> loomsen: and if you put an index on area? 
[15:59] <loomsen> robe2: should i use any special params or just index on area?
[15:59] <robe2> I'm thinking the order by is just causing much more memory usage and forcing detoasting of the geometries so the fatter postgis 2+ geometries are being penalized more
[16:00] <robe2> loomsen just index on area (it would just be a btree which is the default)
[16:03] <robe2> actually that subselect is totally unnessary.  How does: SELECT ST_SRID("geometry")  FROM osm_landusages_gen1 ORDER BY area DESC LIMIT 1; work
[16:03] <robe2> actually that subselect is totally unnessary.  How does: SELECT ST_SRID("geometry")  FROM osm_landusages_gen1 WHERE "geometry" is not null ORDER BY area DESC LIMIT 1; work
[16:04] <loomsen> oh hehe
[16:05] <loomsen> robe2: Total runtime: 1874.131 ms for postgis2, Total runtime: 1948.415 ms  on postgis 1.5
[16:05] <robe2> loomsen: is that after index or the revised query or both?
[16:06] <loomsen> robe2: it's the revised query before the index, i'm not quite sure how to create it ^^ create index area_idx on osm_landusages_gen1   seems to be missing something
[16:08] <robe2> loomsen: CREATE INDEX idx_osm_landusages_gen1_area ON osm_landusages_gen1 USING btree(area);
[16:09] <loomsen> robe2: thank you
[16:09] <loomsen> robe2:  Total runtime: 6.347 ms  that's the revised query with the index
[16:10] <loomsen> robe2: wow, and that's  Total runtime: 6.276 ms   the time for the initial query
[16:12] <robe2> loomsen: as far as queries that would use spatial index.  try: SELECT u."geometry", u.type, u.area FROM osm_landusages_gen1 As u INNER JOIN (SELECT "geometry" FROM osm_landusages_gen1 LIMIT 1) As ref ON ST_Intersects(u.geometry, ref.geometry);
[16:13] <robe2> hopefully didn't make a typo there.
[16:13] <loomsen> robe2:  Total runtime: 39.236 ms on postgis2, and  Total runtime: 30.582 ms on postgis 1
[16:15] <robe2> loomsen: so I guess lesson learned postgis 2+ is not absolutely faster than 1.5 for all things.  It should be for the important things though
[16:15] <robe2> things like ST_SRID are generally looked up in the geometry_columns table, or they are the same across the table anyway so you don't need the order by (just the limit 1).  ORDER BY can slow things down a lot especially if you don't have an index on order by field
[16:16] <robe2> part of the difference I do suspect is that we went to double precision for bbox etc. in 2+ which made spatial checks better but made things a bit heftier.  strk probably has a better idea of the gory details.
[16:16] <loomsen> robe2: the seed process is still taking ages, so the index didn't help there :(
[16:17] <loomsen> http://i.imgur.com/PMohzXs.png
[16:17] <robe2> seed process?
[16:17] <loomsen> robe2: it's insane, like I said, if I raise work_mem for postgres, it's grinding the RAM instead of the SSD, but isn't much faster
[16:18] <loomsen> robe2: for pre rendering tiles
[16:19] <robe2> loomsen: you have an example query of what the tile thing is doing. If you have logging turned on it should be in your pg_log files
[16:19] <robe2> oh you can look at the .yaml maybe that has it.
[16:21] <robe2> loomsen: What does your shared_buffers look like.  That's generally more important than work_mem
[16:22] <robe2> particularly for simple queries that end up touching the same data which is much of what tile generation queries are.
[16:22] <loomsen> robe2: i've been tuning shared buffers up to 8GB
[16:23] <loomsen> which also didn't help, i've tried a lot of different settings and setups, all the same for postgis2
[16:23] <robe2> and how much memory do you have on motherboard?
[16:23] <loomsen> 32G
[16:23] <robe2> and just to make sure you restarted the service after you changed that right?
[16:24] <loomsen> :)
[16:25] <loomsen> sure, I've been through this for like 3 weeks now, using centos, fedora and ubuntu containers, centos bare metal installs, postgres 9.1 and 9.3 repos with corresponding postgis2 releases. all on the same set of hardware
[16:26] <loomsen> tuning postgres with pgtune, letting it alone, nothing helped, really. I already gave up and brought 1.5 back up to production. but it doesn't let me go :)
[16:27] * darkblue_b has some double-bbox test numbers somewhere..
[16:27] <robe2> loomsen: could be a real issue.  If you can show a sample query of the seed routine that would help.
[16:27] <robe2> darkblue_b: I had some too.  When I was testing, when we were deciding on this, I didn't notice much of a difference as I recall.  That;s why I waved my okay flag :)
[16:28] <darkblue_b> its early here - but, is all this really about the difference between "Total runtime: 6.146 ms on postgis2, Total runtime: 6.059 ms on 1.5" ?
[16:28] <robe2> darkblue_b: no
[16:29] <robe2> darkblue_b:  it's about the seed routine on loomsen's taking forever with 2+ compared to 1.5
[16:29] <robe2> http://i.imgur.com/PMohzXs.png
[16:29] <loomsen> https://gist.github.com/loomsen/0e5bd1fe203cd967a3e9
[16:29] <sigq> Title: gist:0e5bd1fe203cd967a3e9 (at gist.github.com)
[16:29] <darkblue_b> forever - *thats* serious ;-)
[16:29] <loomsen> here are some logs
[16:29] <loomsen> let me know if it's enough, I can post more if you want
[16:30] <darkblue_b> whoa - nice setup
[16:31] <robe2> loomsen: are these 1.5 numbers or 2.0?  I presume not 2.1 since you said you don't have that currenlty running.
[16:31] <loomsen> robe2: right, 2.0 
[16:32] <robe2> hmm those numbers look okay all under 2ms
[16:32] <robe2> loomsen: What does your 1.5 look like?
[16:32] <loomsen> yes, it's really nerve wrecking
[16:32] <loomsen> hold on
[16:33] <darkblue_b> loomsen: are there performance number difference (outside the thousandths) between Linux distros?
[16:34] <loomsen> darkblue_b: no, well, not between bare metal centos and openvz containers (which obviously all are running on the same kernel)
[16:34] <darkblue_b> seems unlikely to me, but facts tell the story...
[16:34] <darkblue_b> yeah
[16:37] <loomsen> https://gist.github.com/loomsen/16db0d02be5da1c26147
[16:37] <sigq> Title: postgis 1.5 queries (at gist.github.com)
[16:37] <loomsen> here we go, the 1.5 queries
[16:37] <loomsen> https://gist.github.com/loomsen/0e5bd1fe203cd967a3e9
[16:37] <sigq> Title: postgis 1.5 (at gist.github.com)
[16:37] <loomsen> even better maybe
[16:42] <darkblue_b> osm data is in SRID 900913 ?
[16:42] <loomsen> yep
[16:42] <robe2> loomsen: hmm kind of hard to follow since the queries aren't exactly the same.  Like the 1.5 seems to have more bounding box queries at a cursory glance
[16:43] <robe2> darkblue_b: yah all these osm loaders have standardized on 900913 -- its ingrained in dna.  
[16:43] <darkblue_b> thats ... odd
[16:43] <robe2> we'll never be able to get rid of that fake spatial ref sys
[16:43] <loomsen> robe2: hmm, yeah, I don't quite know how to do this better :) but it's rather obvious that most queries are running fine
[16:44] <robe2> loomsen: try running the same query in both from that -- like that first turning_circle one in your 1.5 log output.  How does it fair in 2.0/2.1
[16:45] <darkblue_b> is this the same libgeos ?
[16:46] <robe2> what is see as first query in your 2.0 has no bounding box  which is really odd since your second 1.5 one that seems almost equivalent has a bounding box
[16:47] <loomsen> let me run the queries, hold on 
[16:47] <robe2> could be something really stupid like imposm (is that what you are using?)  is treating 2.0 differently in a kind of bizarre way
[16:47] <loomsen> i'm using imposm yes
[16:51] <loomsen> robe2: https://gist.github.com/loomsen/d107f5c96ecb05c0c1e4
[16:51] <loomsen> those are the queries
[16:51] <sigq> Title: 1.5 (at gist.github.com)
[16:51] <loomsen> same, i'd say 
[16:52] <robe2> 2.0 is slightly faster :)
[16:52] <robe2> and the first query?
[16:52] <loomsen> hehe
[16:52] <loomsen> which one do you mean?
[16:53] <robe2> the second one in your 1.5: duration: 2.030 ms  parse <unnamed>:
[16:53] <robe2> I meant second sorry not first
[16:54] <robe2> I wonder if the issue is not the query but something imposm is doing with rendering
[16:54] <darkblue_b> reading imposm 2.5 from git, it seems there is a test for PostGIS 2.0+ once, and a flag is set use_geometry_columns_table
[16:55] <darkblue_b> .. every test on use_geometry_columns_table  only chooses .. how to write to geometry_columns
[16:55] <darkblue_b> I dont see any examples of using a test for PostGIS 2.0+ to generate different queries.. but you know, code can fool you that way
[16:56] <loomsen> https://gist.github.com/loomsen/d107f5c96ecb05c0c1e4 updated
[16:56] <sigq> Title: 1.5 (at gist.github.com)
[16:56] <robe2> darblue_b:  what I find really odd about the 2.0 queries loomsen shows is they are all doing a SELECT * and don't have ST_AsBinary, but the 1.5s do
[16:57] <robe2> If we are comparing queries from same imposm calls it does seem to be treating 2.0 very differently for some reason
[16:58] <darkblue_b> psycopg2.Binary(geom.wkb)
[16:58] <darkblue_b> hmm
[16:58] <darkblue_b> there are no explicit ST_AsBinary anythings in the imposm sources, as far as I can see now
[16:58] <darkblue_b> (ore-coffee)
[16:59] <darkblue_b> (pre-coffee)
[16:59] <loomsen> the seed is done by mapproxy-seed util
[16:59] <loomsen> imposm just imports the database actually
[16:59] <darkblue_b> oohhh
[16:59] <loomsen> the only difference is in setting up postgis, 1.5 was reading in 2 sql files, 2.X by create extension postgis
[17:00] <robe2> well the second query is a bit of a concern difference in speed.  Can you run that a couple of times
[17:00] <loomsen> sure
[17:01] <robe2> I think its worth a ticket probably
[17:01] <robe2> but still puzzled why the queries are different between the two.  So mapproxy-seed is generating the queries?
[17:01] <loomsen> robe2: second 15ms, consecutive ones 6ms
[17:01] <loomsen> robe2: it is
[17:02] <robe2> and same version of mapproxy-seed being used?
[17:02] <loomsen> yep, it's a binary in mapproxy, and it's the same mapproxy version yes
[17:02] <robe2> loomsen: second and consecutive (on 1.5 how is that or was that 1.5)
[17:02] <loomsen> no that was 2
[17:03] <loomsen> robe2: 18ms, 9ms
[17:04] * darkblue_b looks at map-proxy a bit
[17:07] <robe2> hmm hard to tell if that initial 75ms vs. 35ms is a concern or not.  We definitely should take a closer look at mapproxy to see why its generating different queries
[17:08] * robe2 takes a look at mapproxy too
[17:08] <loomsen> :)
[17:08] <robe2> loomsen you running 1.6?
[17:09] <loomsen> robe2: yes
[17:15] <loomsen> actually, what i was just thinking, the queries might be a little off because we created the index on area? (though imposm does create a lot of indexes after the import) hmm.
[17:15] <loomsen> well, forget it, the seed process is still taking ages, so ignore that last bit :)
[17:25] <darkblue_b> mapproxy/util/geom.py   ..   load_ogr_datasource()
[17:25] <darkblue_b> is the closest thing I see to a PostGIS client in mapproxy.. but I am not awake yet
[17:26] <darkblue_b> in which case it is gdal/ogr that is emitting the sql
[17:26] <darkblue_b> a certain author is here on the channel.. :-)  but we dont have to bother people
[17:27] <loomsen> it's very nice of you guys helping me with this, thanks for your effort :) 
[17:27] <darkblue_b> well this is a rather important use case I think
[17:27] <loomsen> well, let's hope he reads this :)
[17:27] <loomsen> it is indeed
[17:30] <loomsen> I created rpm packages for all the software, I could grant access to those if necessary. it will install our system to the point where you just have to run an import. or I can make archives of the containers or something, if that helps
[17:33] <darkblue_b> ok - what does this return ?    ogrinfo --version  
[17:34] <loomsen> GDAL 1.7.3, released 2010/11/10  same on both darkblue_b 
[17:34] <darkblue_b> aha
[17:34] <darkblue_b> there have been three releases of GDAL since then
[17:34] <darkblue_b> 1.10 is current.. 
[17:34] <darkblue_b> Dec 2013
[17:35] <darkblue_b> a lot of imortant work on the Postgres/PostGIS driver btw.. definitely
[17:36] <loomsen> ok, I'm gonna build an rpm and test that
[17:36] * darkblue_b goes for a walk
[17:36] <loomsen> oh there's a repo, nice
[17:39] <loomsen> hmm, i should probably rebuild all the binaries against the new gdal-devel
[17:40] <darkblue_b> just 1.10 anything
[17:41] <loomsen> ok, that seems to have broken something, the seed process is throwing errors now
[17:45] <loomsen> sigh, I'm gonna give up for today and if you guys are up to, we're gonna continue this tomorrow when I rebuilt everything :(
[17:49] <loomsen> I'm just going to setup a fedora machine with the latest packages, it has gdal 1.10