PostGIS 2.2.0 upgrade issue

[peters]

I am currently running PostGIS 2.1.8:

POSTGIS="2.1.8 r13780" GEOS="3.5.0-CAPI-1.9.0 r4084" PROJ="Rel. 4.8.0, 6 March 2012" GDAL="GDAL 1.11.2, released 2015/02/10" LIBXML="2.9.1" LIBJSON="UNKNOWN" TO POLOGY RASTER

On Postgres 9.4.5: PostgreSQL 9.4.5 on x86_64-unknown-linux-gnu, compiled by gcc (GCC) 4.4.7 20120313 (Red Hat 4.4.7-16), 64-bit

On CENTOS: Linux hsi 2.6.32-504.16.2.el6.x86_64 #1 SMP Wed Apr 22 06:48:29 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux

I recently built and installed geos 3.5 (was running 3.4.2), and built and installed PostGIS 2.2.0 (OS level) without apparent issue.

I then attempted to upgrade the database by running “ALTER EXTENSION postgis UPDATE”. I get a single error message, and a back end that spins at 100% CPU:

WARNING: 'postgis.backend' is already set and cannot be changed until you reconnect

No other apparent disk or database activity. Pg_stat_activity just shows the “alter extension” command. I had to kill the back end.

Note that this database does have a full tiger data set loaded; not sure if that matters here. I don’t really want to reload everything (over 1 TB).

Any suggestions?

Thanks, Peter Sylvester MITRE Corp.

[robe]

peters,

You don't by chance have sfcgal installed in your 2.1.8? I thought we had fixed this issue, but this issue arises if you happen to have 2 postgis-..so versions running.

I don't think tiger is an issue, since I've upgraded several 2.1s that had tiger to 2.2 without issue.

[robe]

I'm going to close this out since no response from user and not sure how to replicate.

[norbyte]

I have the same issue with upgrading PostGIS 2.1.8 to 2.2.1.

Version: PostgreSQL 9.5.0 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 4.8.5 20150623 (Red Hat 4.8.5-4), 64-bit POSTGIS="2.1.8 r13780" GEOS="3.5.0-CAPI-1.9.0 r4084" PROJ="Rel. 4.8.0, 6 March 2012" GDAL="GDAL 1.11.2, released 2015/02/10" LIBXML="2.9.1" RASTER

New version: POSTGIS="2.2.1 r14555" GEOS="3.5.0-CAPI-1.9.0 r4084" PROJ="Rel. 4.8.0, 6 March 2012" GDAL="GDAL 1.11.2, released 2015/02/10" LIBXML="2.9.1" LIBJSON="0.11" RASTER

When trying to upgrade PostGIS the query hangs with 100% cpu usage and I get the following output:

xxxx=# alter extension postgis update to '2.2.1';
WARNING:  'postgis.backend' is already set and cannot be changed until you reconnect
CONTEXT:  SQL statement "SELECT                  postgis_lib_version()"
PL/pgSQL function postgis_major_version_check() line 21 at SQL statement

Stack trace of the hung backend:

#0  rt_set_handlers (allocator=0x7f69628c0410 <rt_pg_alloc>, reallocator=0x7f69628c0430 <rt_pg_realloc>, deallocator=0x7f69628c0420 <rt_pg_free>, error_handler=0x7f69628c0a40 <rt_pg_error>,
    info_handler=0x7f69628c09a0 <rt_pg_debug>, warning_handler=0x7f69628c0900 <rt_pg_notice>) at rt_context.c:169
#1  0x00007f69582c76e9 in init_rt_allocator (size=3904) at rt_api.c:881
#2  0x00007f69582cf5da in rt_raster_gdal_drivers (drv_count=drv_count@entry=0x7fff637188b4, cancc=cancc@entry=0 '\000') at rt_api.c:8975
#3  0x00007f69582a41d3 in rtpg_assignHookGDALEnabledDrivers () at rt_pg.c:172
#4  _PG_init () at rt_pg.c:291
#5  0x0000000000799d5a in internal_load_library (libname=libname@entry=0x3ab1c50 "/usr/pgsql-9.5/lib/rtpostgis-2.1.so") at dfmgr.c:280
#6  0x000000000079a573 in load_external_function (filename=filename@entry=0x3ab1b90 "$libdir/rtpostgis-2.1", funcname=funcname@entry=0x3ab1b60 "RASTER_lib_version",
    signalNotFound=signalNotFound@entry=1 '\001', filehandle=filehandle@entry=0x7fff63718a68) at dfmgr.c:109
#7  0x000000000079b275 in fmgr_info_C_lang (procedureTuple=0x36800f8, finfo=0x3aafc80, functionId=17689) at fmgr.c:351
#8  fmgr_info_cxt_security (functionId=functionId@entry=17689, finfo=finfo@entry=0x3aafc80, mcxt=mcxt@entry=0x3ac7ff0, ignore_security=ignore_security@entry=0 '\000') at fmgr.c:282
#9  0x000000000079b537 in fmgr_info_cxt (functionId=functionId@entry=17689, finfo=finfo@entry=0x3aafc80, mcxt=mcxt@entry=0x3ac7ff0) at fmgr.c:172
#10 0x00000000005b170f in init_fcache (foid=17689, input_collation=0, fcache=fcache@entry=0x3aafc60, fcacheCxt=0x3ac7ff0, needDescForSets=needDescForSets@entry=1 '\001') at execQual.c:1328
#11 0x00000000005b52a0 in ExecEvalFunc (fcache=0x3aafc60, econtext=0x3ab0470, isNull=0x7fff63718bd4 "", isDone=0x0) at execQual.c:2393
#12 0x00000000005b5ecc in ExecEvalExprSwitchContext (expression=expression@entry=0x3aafc60, econtext=<optimized out>, isNull=isNull@entry=0x7fff63718bd4 "", isDone=isDone@entry=0x0) at execQual.c:4391
#13 0x0000000000636e8b in evaluate_expr (expr=<optimized out>, result_type=result_type@entry=25, result_typmod=result_typmod@entry=-1, result_collation=result_collation@entry=100) at clauses.c:4643
#14 0x0000000000639a76 in evaluate_function (func_tuple=0x36800f8, context=0x7fff63718f60, funcvariadic=0 '\000', args=0x0, input_collid=0, result_collid=100, result_typmod=-1, result_type=25,
    funcid=17689) at clauses.c:4203
#15 simplify_function (funcid=17689, result_type=25, result_typmod=-1, result_collid=result_collid@entry=100, input_collid=input_collid@entry=0, args_p=args_p@entry=0x7fff63718d70,
    funcvariadic=funcvariadic@entry=0 '\000', process_args=process_args@entry=1 '\001', allow_non_const=allow_non_const@entry=1 '\001', context=context@entry=0x7fff63718f60) at clauses.c:3842
#16 0x0000000000638cc4 in eval_const_expressions_mutator (node=0x3aac2f0, context=0x7fff63718f60) at clauses.c:2520
#17 0x00000000005e8893 in expression_tree_mutator (node=node@entry=0x3aac2a0, mutator=mutator@entry=0x638420 <eval_const_expressions_mutator>, context=context@entry=0x7fff63718f60) at nodeFuncs.c:2789
#18 0x0000000000638820 in eval_const_expressions_mutator (node=0x3aac2a0, context=0x7fff63718f60) at clauses.c:3492
#19 0x00000000005e872b in expression_tree_mutator (node=node@entry=0x3aac250, mutator=mutator@entry=0x638420 <eval_const_expressions_mutator>, context=context@entry=0x7fff63718f60) at nodeFuncs.c:2684
#20 0x0000000000638820 in eval_const_expressions_mutator (node=0x3aac250, context=context@entry=0x7fff63718f60) at clauses.c:3492
#21 0x000000000063a8af in eval_const_expressions (root=root@entry=0x3aac400, node=<optimized out>) at clauses.c:2362
#22 0x0000000000625cb5 in preprocess_expression (root=root@entry=0x3aac400, expr=<optimized out>, kind=kind@entry=1) at planner.c:720
#23 0x000000000062a5d3 in subquery_planner (glob=glob@entry=0x3aac370, parse=parse@entry=0x3aac110, parent_root=parent_root@entry=0x0, hasRecursion=hasRecursion@entry=0 '\000', tuple_fraction=0,
    subroot=subroot@entry=0x7fff63719070) at planner.c:444
#24 0x000000000062ac2b in standard_planner (parse=0x3aac110, cursorOptions=0, boundParams=0x0) at planner.c:229
#25 0x00000000006a98fc in pg_plan_query (querytree=<optimized out>, cursorOptions=cursorOptions@entry=0, boundParams=boundParams@entry=0x0) at postgres.c:809
#26 0x00000000006a99f4 in pg_plan_queries (querytrees=querytrees@entry=0x3aac0c0, cursorOptions=0, boundParams=boundParams@entry=0x0) at postgres.c:868
#27 0x0000000000784c66 in BuildCachedPlan (plansource=plansource@entry=0x3a74070, qlist=0x3aac0c0, qlist@entry=0x0, boundParams=boundParams@entry=0x0) at plancache.c:938
#28 0x0000000000784f11 in GetCachedPlan (plansource=0x3a74070, boundParams=boundParams@entry=0x0, useResOwner=<optimized out>) at plancache.c:1152
#29 0x00000000005d59f2 in SPI_plan_get_cached_plan (plan=<optimized out>) at spi.c:1705
#30 0x00007f6965e8b526 in exec_simple_check_plan (expr=0x3aa9948) at pl_exec.c:6538
#31 exec_prepare_plan (expr=expr@entry=0x3aa9948, cursorOptions=cursorOptions@entry=0, estate=0x7fff63719710) at pl_exec.c:3484
#32 0x00007f6965e8e738 in exec_stmt_execsql (estate=estate@entry=0x7fff63719710, stmt=stmt@entry=0x3aa9a28) at pl_exec.c:3516
#33 0x00007f6965e8fc67 in exec_stmt (stmt=0x3aa9a28, estate=0x7fff63719710) at pl_exec.c:1544
#34 exec_stmts (estate=0x7fff63719710, stmts=<optimized out>) at pl_exec.c:1439
#35 0x00007f6965e91949 in exec_stmt_block (estate=estate@entry=0x7fff63719710, block=block@entry=0x3aaa2d0) at pl_exec.c:1238
#36 0x00007f6965e8f82f in exec_stmt (stmt=0x3aaa2d0, estate=0x7fff63719710) at pl_exec.c:1472
#37 exec_stmts (estate=0x7fff63719710, stmts=<optimized out>) at pl_exec.c:1439
#38 0x00007f6965e91aa8 in exec_stmt_block (estate=estate@entry=0x7fff63719710, block=0x3aab110) at pl_exec.c:1377
#39 0x00007f6965e91cd1 in plpgsql_exec_function (func=func@entry=0x3ac86e0, fcinfo=fcinfo@entry=0x3aa3f80, simple_eval_estate=simple_eval_estate@entry=0x0) at pl_exec.c:426
#40 0x00007f6965e86d07 in plpgsql_call_handler (fcinfo=0x3aa3f80) at pl_handler.c:253
#41 0x00000000005b1ae2 in ExecMakeFunctionResultNoSets (fcache=0x3aa3f10, econtext=0x3aa3d20, isNull=0x3aa4898 "p\315\365\002", isDone=<optimized out>) at execQual.c:2019
#42 0x00000000005b741d in ExecTargetList (isDone=0x7fff63719a24, itemIsDone=0x3aa49b0, isnull=<optimized out>, values=0x3aa4880, econtext=0x3aa3d20, targetlist=0x3aa4980) at execQual.c:5365
#43 ExecProject (projInfo=<optimized out>, isDone=isDone@entry=0x7fff63719a24) at execQual.c:5580
#44 0x00000000005ca7c2 in ExecResult (node=node@entry=0x3aa3c10) at nodeResult.c:155
#45 0x00000000005b09d8 in ExecProcNode (node=node@entry=0x3aa3c10) at execProcnode.c:385
#46 0x00000000005adb90 in ExecutePlan (dest=0xbcfe60 <donothingDR>, direction=<optimized out>, numberTuples=0, sendTuples=1 '\001', operation=CMD_SELECT, planstate=0x3aa3c10, estate=0x3aa3b00)
    at execMain.c:1549
#47 standard_ExecutorRun (queryDesc=0x3a6fae0, direction=<optimized out>, count=0) at execMain.c:337
#48 0x00007f69eb577065 in pgss_ExecutorRun (queryDesc=0x3a6fae0, direction=ForwardScanDirection, count=0) at pg_stat_statements.c:881
#49 0x00000000005681ae in execute_sql_string (filename=<optimized out>,
    sql=0x28f0f60 "\n-- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -\n-- \n----\n-- PostGIS - Spatial Types for PostgreSQL\n-- http://postgis.net\n--\n-- Copyright (C) 2011 Regina Obe <lr@pcorp.us>\n--\n"...) at extension.c:736
#50 execute_extension_script (extensionOid=extensionOid@entry=16702, control=control@entry=0x284cf88, from_version=from_version@entry=0x284c750 "2.1.8", version=version@entry=0x284cda8 "2.2.1",
    requiredSchemas=requiredSchemas@entry=0x0, schemaName=schemaName@entry=0x28ee8c8 "public", schemaOid=<optimized out>) at extension.c:904
#51 0x00000000005688ad in ApplyExtensionUpdates (extensionOid=extensionOid@entry=16702, pcontrol=pcontrol@entry=0x284c4d0, initialVersion=initialVersion@entry=0x284c750 "2.1.8",
    updateVersions=<optimized out>) at extension.c:2875
#52 0x000000000056acaf in ExecAlterExtensionStmt (stmt=stmt@entry=0x28a9998) at extension.c:2722
#53 0x00000000006af83a in ProcessUtilitySlow (parsetree=parsetree@entry=0x28a9998, queryString=queryString@entry=0x28a8ec0 "alter extension postgis update to '2.2.1';", context=<optimized out>,
    params=params@entry=0x0, completionTag=completionTag@entry=0x7fff6371a8e0 "", dest=0x28a9cd8) at utility.c:1285
#54 0x00000000006aeab1 in standard_ProcessUtility (parsetree=0x28a9998, queryString=0x28a8ec0 "alter extension postgis update to '2.2.1';", context=<optimized out>, params=0x0, dest=0x28a9cd8,
    completionTag=0x7fff6371a8e0 "") at utility.c:892
#55 0x00007f69eb578fc1 in pgss_ProcessUtility (parsetree=0x28a9998, queryString=0x28a8ec0 "alter extension postgis update to '2.2.1';", context=PROCESS_UTILITY_TOPLEVEL, params=0x0, dest=0x28a9cd8,
    completionTag=0x7fff6371a8e0 "") at pg_stat_statements.c:990
#56 0x00000000006ac471 in PortalRunUtility (portal=0x2841620, utilityStmt=0x28a9998, isTopLevel=<optimized out>, dest=0x28a9cd8, completionTag=0x7fff6371a8e0 "") at pquery.c:1183
#57 0x00000000006ad005 in PortalRunMulti (portal=portal@entry=0x2841620, isTopLevel=isTopLevel@entry=1 '\001', dest=dest@entry=0x28a9cd8, altdest=altdest@entry=0x28a9cd8,
    completionTag=completionTag@entry=0x7fff6371a8e0 "") at pquery.c:1314
#58 0x00000000006adaac in PortalRun (portal=portal@entry=0x2841620, count=count@entry=9223372036854775807, isTopLevel=isTopLevel@entry=1 '\001', dest=dest@entry=0x28a9cd8,
    altdest=altdest@entry=0x28a9cd8, completionTag=completionTag@entry=0x7fff6371a8e0 "") at pquery.c:812
#59 0x00000000006ab883 in exec_simple_query (query_string=0x28a8ec0 "alter extension postgis update to '2.2.1';") at postgres.c:1104
#60 PostgresMain (argc=<optimized out>, argv=argv@entry=0x2828210, dbname=0x28280c0 "xxxx", username=<optimized out>) at postgres.c:4030
#61 0x0000000000468f61 in BackendRun (port=0x284ec30) at postmaster.c:4237
#62 BackendStartup (port=0x284ec30) at postmaster.c:3913
#63 ServerLoop () at postmaster.c:1684
#64 0x0000000000655626 in PostmasterMain (argc=argc@entry=3, argv=argv@entry=0x2827270) at postmaster.c:1292
#65 0x0000000000469b8e in main (argc=3, argv=0x2827270) at main.c:223

One strange thing I noticed in the stack trace is that the backend tries to load a function from PostGIS 2.1 at frame #5 ("/usr/pgsql-9.5/lib/rtpostgis-2.1.so"), however at frame #1 the init_rt_allocator() function in rtpostgis-2.1.so ends up calling the rt_set_handlers() (IP 0x7f69582a41d3) of rtpostgis-2.2.so!

0x00007f69628c0310  0x00007f6962925318  Yes         /usr/pgsql-9.5/lib/rtpostgis-2.2.so
0x00007f69582a1ae0  0x00007f6958301b28  Yes         /usr/pgsql-9.5/lib/rtpostgis-2.1.so

It seems to me that loading both rtpostgis-2.1.so and rtpostgis-2.2.so causes some kind of problem with library initialization?

[strk]

The infinite loop should be fixed in current 2.2 branch, see #3429