Opened 6 years ago

Closed 6 years ago

#2878 closed defect (fixed)

winnie coughing up blood when trying to build cunit for twkb

Reported by: robe Owned by: nicklas
Priority: blocker Milestone: PostGIS 2.2.0
Component: postgis Version: master
Keywords: Cc:

Description

It started today I think after r12867

Debbie seems to be fine with the changes.

libtool: link: x86_64-w64-mingw32-gcc -g -O2 -Wall -Wmissing-prototypes -I/projects/geos/rel-3.5.0devw64gcc48/include -I/projects/proj/rel-4.8.0w64gcc48/include -I/projects/postgresql/rel/pg9.4w64gcc48/include -I/projects/rel-libiconv-1.13.1w64gcc48/include -I.. -I/projects/CGAL/rel-sfcgal-1.0.4w64gcc48/include -DHAVE_SFCGAL -o .libs/cu_tester cu_algorithm.o cu_buildarea.o cu_clean.o cu_print.o cu_misc.o cu_ptarray.o cu_geodetic.o cu_geos.o cu_tree.o cu_measures.o cu_node.o cu_libgeom.o cu_split.o cu_stringbuffer.o cu_triangulate.o cu_homogenize.o cu_force_sfs.o cu_out_twkb.o cu_out_wkt.o cu_out_wkb.o cu_out_gml.o cu_out_kml.o cu_out_geojson.o cu_out_svg.o cu_out_encoded_polyline.o cu_surface.o cu_out_x3d.o cu_in_geojson.o cu_in_wkb.o cu_in_wkt.o cu_in_encoded_polyline.o cu_varint.o cu_tester.o cu_sfcgal.o  ../.libs/liblwgeom.a -L/projects/postgresql/rel/pg9.4w64gcc48/lib -L/projects/gdal/rel-1.11.0w64gcc48/lib -L/projects/rel-libiconv-1.13.1w64gcc48/lib -L/projects/geos/rel-3.5.0devw64gcc48/lib -L/projects/proj/rel-4.8.0w64gcc48/lib -L/projects/json-c/rel-0.12w64gcc48/lib -L/projects/CGAL/rel-sfcgal-1.0.4w64gcc48/lib /projects/proj/rel-4.8.0w64gcc48/lib/libproj.dll.a /projects/json-c/rel-0.12w64gcc48/lib/libjson-c.a -lgeos_c /mingw/x86_64-w64-mingw32/lib/libcunit.a -L/projects/CUnit-2.1-2/CUnit/Sources /projects/CGAL/rel-sfcgal-1.0.4w64gcc48/lib/libSFCGAL.dll -L/projects/proj/rel-4.8.0w64gcc48/lib -L/projects/CGAL/rel-sfcgal-1.0.4w64gcc48/lib
../.libs/liblwgeom.a(lwout_twkb.o): In function `varint_u32_encoded_size':
e:\jenkins\postgis\branches\2.2\liblwgeom/varint.h:63: multiple definition of `varint_u32_encoded_size'
cu_varint.o:e:\jenkins\postgis\branches\2.2\liblwgeom\cunit/../varint.h:63: first defined here
../.libs/liblwgeom.a(lwout_twkb.o): In function `varint_u32_encode_buf':
e:\jenkins\postgis\branches\2.2\liblwgeom/varint.h:78: multiple definition of `varint_u32_encode_buf'
cu_varint.o:e:\jenkins\postgis\branches\2.2\liblwgeom\cunit/../varint.h:78: first defined here
../.libs/liblwgeom.a(lwout_twkb.o): In function `varint_s32_encoded_size':
e:\jenkins\postgis\branches\2.2\liblwgeom/varint.h:83: multiple definition of `varint_s32_encoded_size'
cu_varint.o:e:\jenkins\postgis\branches\2.2\liblwgeom\cunit/../varint.h:83: first defined here
../.libs/liblwgeom.a(lwout_twkb.o): In function `varint_s32_encode_buf':
e:\jenkins\postgis\branches\2.2\liblwgeom/varint.h:99: multiple definition of `varint_s32_encode_buf'
cu_varint.o:e:\jenkins\postgis\branches\2.2\liblwgeom\cunit/../varint.h:99: first defined here
../.libs/liblwgeom.a(lwout_twkb.o): In function `varint_s64_encoded_size':
e:\jenkins\postgis\branches\2.2\liblwgeom/varint.h:105: multiple definition of `varint_s64_encoded_size'
cu_varint.o:e:\jenkins\postgis\branches\2.2\liblwgeom\cunit/../varint.h:105: first defined here
../.libs/liblwgeom.a(lwout_twkb.o): In function `varint_s64_encode_buf':
e:\jenkins\postgis\branches\2.2\liblwgeom/varint.h:122: multiple definition of `varint_s64_encode_buf'
cu_varint.o:e:\jenkins\postgis\branches\2.2\liblwgeom\cunit/../varint.h:122: first defined here
../.libs/liblwgeom.a(lwout_twkb.o): In function `varint_u64_encoded_size':
e:\jenkins\postgis\branches\2.2\liblwgeom/varint.h:128: multiple definition of `varint_u64_encoded_size'
cu_varint.o:e:\jenkins\postgis\branches\2.2\liblwgeom\cunit/../varint.h:128: first defined here
../.libs/liblwgeom.a(lwout_twkb.o): In function `varint_u64_encode_buf':
e:\jenkins\postgis\branches\2.2\liblwgeom/varint.h:143: multiple definition of `varint_u64_encode_buf'
cu_varint.o:e:\jenkins\postgis\branches\2.2\liblwgeom\cunit/../varint.h:143: first defined here
../.libs/liblwgeom.a(lwout_twkb.o):lwout_twkb.c:(.rdata+0x2f4): multiple definition of `varint_s32_max'
cu_varint.o:cu_varint.c:(.rdata+0x1e0): first defined here
../.libs/liblwgeom.a(lwout_twkb.o):lwout_twkb.c:(.rdata+0x2f8): multiple definition of `varint_s32_min'
cu_varint.o:cu_varint.c:(.rdata+0x1e4): first defined here
../.libs/liblwgeom.a(lwout_twkb.o):lwout_twkb.c:(.rdata+0x2fc): multiple definition of `varint_u32_max'
cu_varint.o:cu_varint.c:(.rdata+0x1e8): first defined here
../.libs/liblwgeom.a(lwout_twkb.o):lwout_twkb.c:(.rdata+0x300): multiple definition of `varint_s64_max'
cu_varint.o:cu_varint.c:(.rdata+0x1f0): first defined here
../.libs/liblwgeom.a(lwout_twkb.o):lwout_twkb.c:(.rdata+0x308): multiple definition of `varint_s64_min'
cu_varint.o:cu_varint.c:(.rdata+0x1f8): first defined here
../.libs/liblwgeom.a(lwout_twkb.o):lwout_twkb.c:(.rdata+0x310): multiple definition of `varint_u64_max'
cu_varint.o:cu_varint.c:(.rdata+0x200): first defined here
../.libs/liblwgeom.a(lwout_wkb.o): In function `hexbytes_from_bytes':
e:\jenkins\postgis\branches\2.2\liblwgeom/lwout_wkb.c:24: multiple definition of `hexbytes_from_bytes'
cu_out_twkb.o:e:\jenkins\postgis\branches\2.2\liblwgeom\cunit/cu_out_twkb.c:54: first defined here
collect2.exe: error: ld returned 1 exit status
Makefile:83: recipe for target `cu_tester' failed
make[2]: *** [cu_tester] Error 1
make[2]: Leaving directory `/projects/postgis/branches/2.2/liblwgeom/cunit'
Makefile:156: recipe for target `check' failed
make[1]: *** [check] Error 2
make[1]: Leaving directory `/projects/postgis/branches/2.2/liblwgeom'
GNUmakefile:14: recipe for target `check' failed
make: *** [check] Error 1

Change History (22)

comment:1 Changed 6 years ago by robe

Owner: changed from pramsey to nicklas

comment:2 Changed 6 years ago by robe

I tried building on my pc too and ran into same issues.

We are both running gcc 4.8.0 or 4.8.1 building also with sfcgal. Debbie is on a lower gcc and is not building with sfcgal yet.

comment:3 Changed 6 years ago by robe

Resolution: fixed
Status: newclosed

should be fixed at r12871

Will wait for winnie to give an okay sign before I close.

comment:4 Changed 6 years ago by robe

all bots are happy.

comment:5 Changed 6 years ago by pramsey

I'm not. Warnings should not be raised in compilation, and this header raises them for defining functions w/o prototypes.

comment:6 Changed 6 years ago by robe

I think we have a bunch of those. Like there is still one for SFCGAL that bugs me. I think I got rid of one but in looking thru the compile I found another.

We should have separate tickets to itemize those. I'll start now.

comment:7 Changed 6 years ago by nicklas

I put back varint.h in cu_varint.c in r12876.

Then I see no more warnings.

I guess winnie will tell if she is happy too :-)

comment:8 Changed 6 years ago by robe

Resolution: fixed
Status: closedreopened

nope now she's very angry and grinding her teeth :) Your r12875 commit was okay and then she started growling at r12876

../.libs/liblwgeom.a(lwout_twkb.o): In function `_varint_u64_encoded_size':
e:\jenkins\postgis\branches\2.2\liblwgeom/varint.h:53: multiple definition of `_varint_u64_encoded_size'
cu_varint.o:e:\jenkins\postgis\branches\2.2\liblwgeom\cunit/../varint.h:53: first defined here
../.libs/liblwgeom.a(lwout_twkb.o): In function `_varint_u64_encode_buf':
e:\jenkins\postgis\branches\2.2\liblwgeom/varint.h:60: multiple definition of `_varint_u64_encode_buf'
cu_varint.o:e:\jenkins\postgis\branches\2.2\liblwgeom\cunit/../varint.h:60: first defined here
../.libs/liblwgeom.a(lwout_twkb.o): In function `varint_u32_encoded_size':
e:\jenkins\postgis\branches\2.2\liblwgeom/varint.h:75: multiple definition of `varint_u32_encoded_size'
cu_varint.o:e:\jenkins\postgis\branches\2.2\liblwgeom\cunit/../varint.h:75: first defined here
../.libs/liblwgeom.a(lwout_twkb.o): In function `varint_u32_encode_buf':
e:\jenkins\postgis\branches\2.2\liblwgeom/varint.h:90: multiple definition of `varint_u32_encode_buf'
cu_varint.o:e:\jenkins\postgis\branches\2.2\liblwgeom\cunit/../varint.h:90: first defined here
../.libs/liblwgeom.a(lwout_twkb.o): In function `varint_s32_encoded_size':
e:\jenkins\postgis\branches\2.2\liblwgeom/varint.h:95: multiple definition of `varint_s32_encoded_size'
cu_varint.o:e:\jenkins\postgis\branches\2.2\liblwgeom\cunit/../varint.h:95: first defined here
../.libs/liblwgeom.a(lwout_twkb.o): In function `varint_s32_encode_buf':
e:\jenkins\postgis\branches\2.2\liblwgeom/varint.h:111: multiple definition of `varint_s32_encode_buf'
cu_varint.o:e:\jenkins\postgis\branches\2.2\liblwgeom\cunit/../varint.h:111: first defined here
../.libs/liblwgeom.a(lwout_twkb.o): In function `varint_s64_encoded_size':
e:\jenkins\postgis\branches\2.2\liblwgeom/varint.h:117: multiple definition of `varint_s64_encoded_size'
cu_varint.o:e:\jenkins\postgis\branches\2.2\liblwgeom\cunit/../varint.h:117: first defined here
../.libs/liblwgeom.a(lwout_twkb.o): In function `varint_s64_encode_buf':
e:\jenkins\postgis\branches\2.2\liblwgeom/varint.h:134: multiple definition of `varint_s64_encode_buf'
cu_varint.o:e:\jenkins\postgis\branches\2.2\liblwgeom\cunit/../varint.h:134: first defined here
../.libs/liblwgeom.a(lwout_twkb.o): In function `varint_u64_encoded_size':
e:\jenkins\postgis\branches\2.2\liblwgeom/varint.h:140: multiple definition of `varint_u64_encoded_size'
cu_varint.o:e:\jenkins\postgis\branches\2.2\liblwgeom\cunit/../varint.h:140: first defined here
../.libs/liblwgeom.a(lwout_twkb.o): In function `varint_u64_encode_buf':
e:\jenkins\postgis\branches\2.2\liblwgeom/varint.h:155: multiple definition of `varint_u64_encode_buf'
cu_varint.o:e:\jenkins\postgis\branches\2.2\liblwgeom\cunit/../varint.h:155: first defined here
../.libs/liblwgeom.a(lwout_twkb.o):lwout_twkb.c:(.rdata+0x2f4): multiple definition of `varint_s32_max'
cu_varint.o:cu_varint.c:(.rdata+0x1e0): first defined here
../.libs/liblwgeom.a(lwout_twkb.o):lwout_twkb.c:(.rdata+0x2f8): multiple definition of `varint_s32_min'
cu_varint.o:cu_varint.c:(.rdata+0x1e4): first defined here
../.libs/liblwgeom.a(lwout_twkb.o):lwout_twkb.c:(.rdata+0x2fc): multiple definition of `varint_u32_max'
cu_varint.o:cu_varint.c:(.rdata+0x1e8): first defined here
../.libs/liblwgeom.a(lwout_twkb.o):lwout_twkb.c:(.rdata+0x300): multiple definition of `varint_s64_max'
cu_varint.o:cu_varint.c:(.rdata+0x1f0): first defined here
../.libs/liblwgeom.a(lwout_twkb.o):lwout_twkb.c:(.rdata+0x308): multiple definition of `varint_s64_min'
cu_varint.o:cu_varint.c:(.rdata+0x1f8): first defined here
../.libs/liblwgeom.a(lwout_twkb.o):lwout_twkb.c:(.rdata+0x310): multiple definition of `varint_u64_max'
cu_varint.o:cu_varint.c:(.rdata+0x200): first defined here
collect2.exe: error: ld returned 1 exit status
Makefile:83: recipe for target `cu_tester' failed
make[2]: *** [cu_tester] Error 1
make[2]: Leaving directory `/projects/postgis/branches/2.2/liblwgeom/cunit'
Makefile:156: recipe for target `check' failed
make[1]: *** [check] Error 2
make[1]: Leaving directory `/projects/postgis/branches/2.2/liblwgeom'
GNUmakefile:14: recipe for target `check' failed
make: *** [check] Error 1

Maybe it's because you are missing an include guard for varint.h?

comment:9 Changed 6 years ago by robe

Nevermind my last comment about missing include guard. I see it has one already hmm yet it still seems to be trying to include it twice. Same issue on my windows 7 mingw compiled desktop.

comment:10 Changed 6 years ago by nicklas

Ok, I have taken away varint.h again in r12877.

But that gives me warnings in GCC 4.82 in linux. More about that in #2880

comment:11 Changed 6 years ago by nicklas

Ok, in r12878 I added varint.h again and removed the liblwgeom_internal.h header instead.

comment:12 Changed 6 years ago by robe

nope fixed for a minute when took out at r12877 and then broken as soon as you r12878 came back.

Are you able to get to winnie okay - http://winnie.postgis.net:1500/job/PostGIS_EDB_regress/1181/consoleFull

I think I may not have reset up permissions on new box so let me know.

-- Warning: REGINA's uneducated opinion coming up --

I suspect you need to move the functions out of varint.h (or we have to live with the warning which is just in cunit thankgoodness or you have to combine your twkb and cu_varint tests in one file.

Since varint is included in both lwout_twkb and cu_varint. I think the issue is the linker (something finicky with mingw evidentally). That both cu_twkb and cu_varint don't consider varint already included each embeds a copy of the functions and when they are linked together it sees duplicate function definitions and chokes. I want to reiterate that I have NO IDEA what I am talking about, so take my opinion with a grain of salt :)

comment:13 Changed 6 years ago by robe

found this which I think says what I thought I was theorizing:

http://stackoverflow.com/questions/7926224/header-include-guards-dont-work

comment:14 Changed 6 years ago by nicklas

Yes, I guess you are right.

The reason for moving the functions into the header file was that I saw a performance regression when they were in a separate file compared to when they were in the lwout_twkb.c file.

The timing on a known data set and query, went from in average about 2850 ms to above 3000 ms. I recompiled and tested back and forward a few times. So it is about 5%. When putting the functions into the header the timings was almost back where we began.

But I think I will have to rewind to the version Sandro wrote with the functions in a varint.c file and take the performance impact.

This is clearly a grey zone where the compilers doesn't fully agree. I guess it can be some setting in the config file that gives this difference?

comment:15 Changed 6 years ago by robe

Hmm that is surprising why such a speed difference. All things I have read (which granted is not much), say speed improvement is so negligable not to bother with that optimization. What test are you running with? Maybe I can test on mingw to see what speed differences are like. Which gcc compiler are you using? I'm using 4.8.0 and 4.8.1.

The code compiles btw I guess because only lwout_twkb includes varint.h in normal operation mode. So just the cunit testing part includes twice.

comment:16 Changed 6 years ago by nicklas

The data set I am testing on is 171 mb. I will try to catch the effect in a smaller scale or from generating the numbers.

I also think that the differnce is actually bigger because what I am doing is writing all geometries from the data set to a new table. So, some of the 3000 ms is just disc writing and unchanged between the two cases.

comment:17 Changed 6 years ago by nicklas

This was very strange.

When I have tried to catch this performance issue mentioned above, I have found that it shows only in some cases. The problem is not directly related to number of calls to varint-functions. And not directly to number of rows doing those calls. But if I ask the query to write a new table with the resulting rows it shows.

So it seems like when the db writs to disc and returns to the next row calling the varint functions it has some overhead, but not if it just iterates the rows with explain analyze.

This is the most obvious case I have found:

Create a table with a lot of points:

create table a as
select 'point(1 1)'::geometry as geom from 
generate_series(1,5000000);

Then if comparing r12835 (varint functions in lwout_twkb.c) with r12836 (varint functions in varint.c) I get interesting results:

On query:

create table c as
select st_astwkb(geom, 0) from a;

r12835 uses always under 4000 ms and r12836 uses between 4400 and 4500 ms. That is more than 10% difference.

But when running

explain analyze
select st_astwkb(geom, 0) from a;

I see more or less no difference.

Another evidence for this is if I use the aggregate function of twkb like:

create table c as
select st_astwkbagg(geom, 0) from a;

Then I also see no diffrence. I guess that is because the database don't go in and out of reading and back tu the encoding functions. Interesting to not is also that doing the last query only takes about 2000 ms. So 2 seconds of overhead is removed by writing the same (almost) at 1 row instead of 5 millon rows.

You can see the same effect when comparing:

create table d as 
select st_asbinary(geom) from a;

which takes about 4000 ms with:

create table d as 
select st_asbinary(st_collect(geom)) from a

which takes about 3100 ms.

I also found that this effect don't show between

create table d as 
select geom from a

and

create table d as 
select st_collect(geom) from a

which both uses about 2400 ms.

In Summary: There is something that takes time to initialize when the database gets back from disc writing. This overhead is smaller in the r12835 where there is fewer calls cross source files than in r12836.

This overhead also shows with other functions like ST_AsBinary.

It doesn't show when no PostGIS function is called like when just copying the geometry as is.

GCC that I am testing on is : gcc version 4.8.2 (Ubuntu 4.8.2-19ubuntu1)

comment:18 Changed 6 years ago by robe

nicklas,

Haven't tried testing yet. Do you have cassert enabled when testing? Just wondering that if you do have it enabled that it might be adding some extra overhead that is not relevant in a production environment.

comment:19 Changed 6 years ago by robe

Did a compare of the 2 on my

PostgreSQL 9.4beta2, compiled by Visual C++ build 1800, 32-bit

Here are my results

-- 2 part means varint.h, varint.c (from r12836)
-- single means varint.h as single file with funcs (from circa r12875)

-- 2 part runs:  5231 ms (fresh restart),  5121ms (fresh restart), 5663 ms (fresh start), 
--      5616ms (fresh start), 4602 ms (warm), 4881ms (warm), 4634ms (warm), 4899ms (warm)
-- single runs: 4991 ms (fresh start), 4649 ms (fresh start), 5554 ms (fresh start),  5523ms (fresh start), 
--      5600 ms (warm), 5507 ms (warm), 4555ms (warm), 4540 ms (warm), 4524 ms (warm)
DROP TABLE IF EXISTS c;
create table c as
select st_astwkb(geom, 0) from a;

and as you said in both cases the explain analyze is consistently the same

-- single run:  execution time (2589.146 ms, plan 1.571ms) (start), execution time (2574.146 ms, plan 0.056ms) (warm), 
--              execution time (2623ms, plan 0.049) (warm), execution time (2555.248ms, plan 0.049) (warm), 

-- 2 part: execution time (2580.143ms, plan 1.093ms) (start), execution time (2612ms, plan 0.049) (warm), execution time (2591.289ms, plan 0.049) (warm)
explain (analyze)
select st_astwkb(geom, 0) from a;

So even though the create table does seem on average faster with having a single file, there is so much noise (particularly with the single) coming from somewhere I really can't tell since some runs are actually slower than the 2 file.

I would say if we have a problem, then as you said it probably affects every output function we have. Might as well just ere on the safe side and break varint back up and put in a separate ticket to investigate this issue.

comment:20 Changed 6 years ago by nicklas

No, no cassert. No options at all.

I forget to write I only tested it warm. I left out the first run after restarting.

As I wrote I earlier found that moving the functions to the header file gave almost the same result as having everything in lwout_twkb.c but in the tests above I test "all i lwout_twkb.c" vs "splitted in lwout_twkb.c and varint.c with header varint.h". I feel more sure about this difference than between r12836 and all varibt functions i varint.h

I will be away till tusdat evening but I think I will try to comit the r12836 state of those files today.

comment:21 Changed 6 years ago by nicklas

Back to version with varint functions in varint.c with definitions in varint.h in r12883.

I will try later this week to investigate the performande issue discussed above and open a new ticket.

First priority is to find out if this happens also when the result is read from a client. If so, this is worth investigating.

When testing twkb and comparing results with ST_AsBinary I have seen some strange results with ST_AsBinary performing bad. I think this might be the same issue. And reading with ST_AsBinary from a client I guess is the most common usage of PostGIS in all categories (QGIS, Mapnik MapServer and so on)

comment:22 Changed 6 years ago by robe

Resolution: fixed
Status: reopenedclosed

Nicklas,

Thanks. Winnie is happy again so will close this out. I'll help test when you have some more benchmarks.

Note: See TracTickets for help on using tickets.