Re: hung backends stuck in spinlock heavy endless loop

On Tue, Jan 13, 2015 at 7:24 PM, Peter Geoghegan <pg@heroku.com> wrote:
> On Tue, Jan 13, 2015 at 3:54 PM, Merlin Moncure <mmoncure@gmail.com> wrote:
>> Some more information what's happening:
>> This is a ghetto logical replication engine that migrates data from
>> sql sever to postgres, consolidating a sharded database into a single
>> set of tables (of which there are only two). There is only one index
>> on the destination table, and it's composite int,int in both cases.
>
> Does the logical replication engine perform dynamic DDL at all? Does
> it dynamically add columns to the table that everything is being
> consolidated to?

I let the test burn in all night.  It's still exactly where it
was...this is not slow performance, it's stuck.

It works like this:
Dynamically create staging table for inserts/change
Dynamically create staging table for deletes
Dynamically create master table if not present (in this last run, it
was was present)
Dynamically delete from master via delete table
Dynamically delete from master via insert/change table (based on int/int key)
Dynamically insert/select from inserts/change to permanent

There is also some log/tracking information going on in other tables.


Here's a backtrace:

#0  0x0000000000750a97 in spin_delay ()
#1  0x0000000000750b19 in s_lock ()
#2  0x0000000000750844 in LWLockRelease ()
#3  0x0000000000730000 in LockBuffer ()
#4  0x00000000004b2db4 in _bt_relandgetbuf ()
#5  0x00000000004b7116 in _bt_moveright ()
#6  0x00000000004b6e02 in _bt_search ()
#7  0x00000000004b8006 in _bt_first ()
#8  0x00000000004b5aad in btgettuple ()
#9  0x0000000000896656 in FunctionCall2Coll ()
#10 0x00000000004acd55 in index_getnext_tid ()
#11 0x00000000004acfad in index_getnext ()
#12 0x00000000004ac120 in systable_getnext ()
#13 0x0000000000878ce4 in ScanPgRelation ()
#14 0x0000000000879eb1 in RelationBuildDesc ()
#15 0x000000000087bb52 in RelationIdGetRelation ()
#16 0x0000000000495115 in relation_open ()
#17 0x00000000004952f9 in relation_openrv_extended ()
#18 0x000000000049555e in heap_openrv_extended ()
#19 0x000000000057ef0b in parserOpenTable ()
#20 0x000000000056776f in setTargetTable ()
#21 0x000000000053628f in transformDeleteStmt ()
#22 0x000000000053603c in transformStmt ()
#23 0x0000000000535fdb in transformTopLevelStmt ()
#24 0x0000000000535db8 in parse_analyze ()
#25 0x000000000075dd4f in pg_analyze_and_rewrite ()
#26 0x00000000006472a5 in _SPI_execute_plan ()
#27 0x0000000000644551 in SPI_execute ()
#28 0x00007f89b83a8ce7 in exec_stmt_dynexecute () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#29 0x00007f89b83a4c43 in exec_stmt () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#30 0x00007f89b83a495f in exec_stmts () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#31 0x00007f89b83a480a in exec_stmt_block () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#32 0x00007f89b83a2802 in plpgsql_exec_function () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#33 0x00007f89b839cd6a in plpgsql_call_handler () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#34 0x0000000000618805 in ExecMakeTableFunctionResult ()
#35 0x00000000006376ba in FunctionNext ()
#36 0x000000000061f868 in ExecScanFetch ()
#37 0x000000000061f8d7 in ExecScan ()
#38 0x0000000000637a1d in ExecFunctionScan ()
#39 0x0000000000614cfd in ExecProcNode ()
#40 0x0000000000612c32 in ExecutePlan ()
#41 0x00000000006110c3 in standard_ExecutorRun ()
---Type <return> to continue, or q <return> to quit---
#42 0x0000000000610fc5 in ExecutorRun ()
#43 0x0000000000647b02 in _SPI_pquery ()
#44 0x00000000006475e8 in _SPI_execute_plan ()
#45 0x000000000064471d in SPI_execute_plan_with_paramlist ()
#46 0x00007f89b83a85a5 in exec_stmt_execsql () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#47 0x00007f89b83a4c28 in exec_stmt () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#48 0x00007f89b83a495f in exec_stmts () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#49 0x00007f89b83a4429 in exec_stmt_block () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#50 0x00007f89b83a4a5d in exec_stmt () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#51 0x00007f89b83a495f in exec_stmts () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#52 0x00007f89b83a54a5 in exec_stmt_loop () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#53 0x00007f89b83a4aff in exec_stmt () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#54 0x00007f89b83a495f in exec_stmts () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#55 0x00007f89b83a5241 in exec_stmt_if () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#56 0x00007f89b83a4ac9 in exec_stmt () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#57 0x00007f89b83a495f in exec_stmts () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#58 0x00007f89b83a480a in exec_stmt_block () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#59 0x00007f89b83a2802 in plpgsql_exec_function () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#60 0x00007f89b839cd6a in plpgsql_call_handler () from
/home/mmoncure/pg94/lib/postgresql/plpgsql.so
#61 0x0000000000618403 in ExecMakeFunctionResultNoSets ()
#62 0x0000000000618e01 in ExecEvalFunc ()
#63 0x000000000061f0f7 in ExecTargetList ()
#64 0x000000000061f6dd in ExecProject ()
#65 0x0000000000638a03 in ExecResult ()
#66 0x0000000000614c16 in ExecProcNode ()
#67 0x0000000000612c32 in ExecutePlan ()
#68 0x00000000006110c3 in standard_ExecutorRun ()
#69 0x0000000000610fc5 in ExecutorRun ()
#70 0x0000000000764725 in PortalRunSelect ()
#71 0x00000000007643b4 in PortalRun ()
#72 0x000000000075e484 in exec_simple_query ()
#73 0x00000000007626e2 in PostgresMain ()
#74 0x00000000006f463f in BackendRun ()
#75 0x00000000006f3d44 in BackendStartup ()
#76 0x00000000006f075e in ServerLoop ()
#77 0x00000000006efdec in PostmasterMain ()
#78 0x00000000006594ec in main ()

merlin