Hi,
PostgreSQL 9.2.4
Linux 2.6.32
listen_addresses =3D '*'
max_connections =3D 550
shared_buffers =3D 35GB
work_mem =3D 256MB
maintenance_work_mem =3D 1GB
shared_preload_libraries =3D 'pg_stat_statements'
bgwriter_delay =3D 10ms
bgwriter_lru_multiplier =3D 10.0
effective_io_concurrency =3D 32
wal_level =3D hot_standby
synchronous_commit =3D off
checkpoint_segments =3D 1024
checkpoint_timeout =3D 1h
checkpoint_completion_target =3D 0.9
checkpoint_warning =3D 5min
max_wal_senders =3D 3
wal_keep_segments =3D 2048
hot_standby =3D on
max_standby_streaming_delay =3D 5min
hot_standby_feedback =3D on
effective_cache_size =3D 133GB
log_destination =3D 'stderr'
logging_collector =3D on
log_directory =3D '/var/log/pgsql'
log_filename =3D 'postgresql-%Y-%m-%d.log'
log_truncate_on_rotation =3D on
log_rotation_age =3D 1d
log_rotation_size =3D 0
log_checkpoints =3D on
log_line_prefix =3D '%t %p %u@%d from %h [vxid:%v txid:%x] [%i] '
log_lock_waits =3D on
log_statement =3D 'ddl'
log_timezone =3D 'W-SU'
track_activity_query_size =3D 4096
autovacuum_max_workers =3D 5
autovacuum_naptime =3D 5s
autovacuum_vacuum_scale_factor =3D 0.05
autovacuum_analyze_scale_factor =3D 0.05
autovacuum_vacuum_cost_delay =3D 5ms
datestyle =3D 'iso, dmy'
timezone =3D 'W-SU'
lc_messages =3D 'en_US.UTF-8'
lc_monetary =3D 'ru_RU.UTF-8'
lc_numeric =3D 'ru_RU.UTF-8'
lc_time =3D 'ru_RU.UTF-8'
default_text_search_config =3D 'pg_catalog.russian'
pg_stat_statements.track =3D all
Yesterday we faced a segfault on a simple PL/Python function's call:
CREATE OR REPLACE FUNCTION test_test()
RETURNS TABLE("=D0=98=D0=B4=D0=B5=D0=BD=D1=82=D0=B8=D1=84=D0=B8=D0=BA=D1=82=
=D0=BE=D1=80" int, "=D0=93=D0=BE=D1=81. =D0=BD=D0=BE=D0=BC=D0=B5=D1=80" var=
char) AS
$BODY$
import time
cars =3D plpy.prepare("""
select id, ident_code from cars limit 100
""")
for car in plpy.execute(cars):
return car;
$BODY$
LANGUAGE plpythonu VOLATILE
COST 100
ROWS 1000;
It has happened just once and we didn't manage to reproduce this
problem. We have a huge amount of PL/Python code in the database and
have never had this kind of problem before.
Here is the backtrace from the coredump:
(gdb) bt f
#0 0x00000000007381d7 in pfree (pointer=3D0x7eff56a141a0) at mcxt.c:659
header =3D 0x7eff56a14190
#1 0x00007eff56a14927 in PLy_output_tuple_funcs (arg=3D0x1ad6960,
desc=3D0x19d9520) at plpy_typeio.c:199
i =3D <value optimized out>
__func__ =3D "PLy_output_tuple_funcs"
#2 0x00007eff56a0f155 in PLy_function_build_args
(fcinfo=3D0x7fffa59cb6b0, proc=3D0x1ad6940) at plpy_exec.c:416
desc =3D 0x19d9520
save_exception_stack =3D 0x7fffa59cb420
save_context_stack =3D 0x7fffa59cb630
local_sigjmp_buf =3D {{
__jmpbuf =3D {28236528, 5106765649720773924, 1, 28238888,
140735971899056, 140735971900064, -5106611986378781404,
-4962882071449170652},
__mask_was_saved =3D 0,
__saved_mask =3D {
__val =3D {0 <repeats 16 times>}
}
}}
arg =3D 0x0
args =3D 0x7eff62979ef0
i =3D <value optimized out>
__func__ =3D "PLy_function_build_args"
#3 0x00007eff56a0f437 in PLy_exec_function (fcinfo=3D0x7fffa59cb6b0,
proc=3D0x1ad6940) at plpy_exec.c:59
save_exception_stack =3D 0x7fffa59cb560
save_context_stack =3D 0x7fffa59cb630
local_sigjmp_buf =3D {{
__jmpbuf =3D {28236528, 5106765649720773924, 1, 28238888,
140735971899056, 140735971900064, -5106611986395558620,
-4962882071897174748},
__mask_was_saved =3D 0,
__saved_mask =3D {
__val =3D {13483862011252313380, 0, 0, 0, 192, 11739232,
601, 26726112, 139635135180228, 139635135180228, 7570912, 0, 26987960,
0, 8192, 8388608}
}
}}
rv =3D <value optimized out>
plargs =3D 0x0
plrv =3D 0x0
plerrcontext =3D {
previous =3D 0x7fffa59cbaa0,
callback =3D 0x7375b6 <AllocSetContextCreate+54>,
arg =3D 0x1ad6940
}
__func__ =3D "PLy_exec_function"
#4 0x00007eff56a0ff04 in plpython_call_handler (fcinfo=3D0x7fffa59cb6b0)
at plpy_main.c:236
funcoid =3D <value optimized out>
proc =3D <value optimized out>
save_exception_stack =3D 0x7fffa59cbc70
save_context_stack =3D <value optimized out>
local_sigjmp_buf =3D {{
__jmpbuf =3D {28236528, 5106765649720773924, 1, 28238888,
140735971899056, 140735971900064, -5106611986208912092,
-4962882072010945244},
__mask_was_saved =3D 0,
__saved_mask =3D {
__val =3D {0, 0, 281474976710656, 1043, 28238888,
3324408277, 28238888, 3324408277, 26985416, 0, 0, 28238920, 5790802, 0,
0, 0}
}
}}
---Type <return> to continue, or q <return> to quit---
retval =3D <value optimized out>
exec_ctx =3D 0x19bcdb8
plerrcontext =3D {
previous =3D 0x0,
callback =3D 0x7eff56a0ffb0 <plpython_error_callback>,
arg =3D 0x1aee428
}
__func__ =3D "plpython_call_handler"
#5 0x0000000000587fd5 in ExecMakeTableFunctionResult
(funcexpr=3D0x1aee428, econtext=3D0x1aedaf0, expectedDesc=3D0x1aee1e0,
randomAccess=3D0 '\000') at execQual.c:2156
result =3D 5967294
tupstore =3D 0x0
tupdesc =3D 0x0
funcrettype =3D 2249
returnsTuple =3D 1 '\001'
returnsSet =3D 1 '\001'
fcinfo =3D {
flinfo =3D 0x1aee448,
context =3D 0x0,
resultinfo =3D 0x7fffa59cba60,
fncollation =3D 0,
isnull =3D 0 '\000',
nargs =3D 0,
arg =3D {25859072, 0, 1043, 0 <repeats 20 times>, 7489698, 0,
0, 0, 64, 140735971899536, 4586382, 1, 2, 139635337082480, 7471000, 0,
0, 0, 420013441810432, 3324408277, 0,
4294967295, 7433724, 25962000, 2, 8, 7482628, 0,
140735971899532, 0, 25962288, 8589934592, 25962040, 25962200, 25962176,
25962144, 8589934592, 4479650889751, 40, 25856768,
1043, 4294967295, 100, 0, 7570165, 0, 25962928, 25952256,
25962288, 0, 140735971899960, 25962456, 5991898, 0, 26567760,
140735971852288, 7372282, 8589934594, 26567760, 1043,
26567760, 140735971899792, 26567760, 140735971899856,
7372282, 26786736, 26567760, 1043, 26567760, 140735971899856, 7378619,
6981568, 140735971899856, 2, 0, 139635337081568,
287762808832, 1125891316908032, 0, 6981568, 281483566645432},
argnull =3D "\002", '\000' <repeats 16 times>"\224, \212\001",
'\000' <repeats 12 times>, "\023\004", '\000' <repeats 65 times>
}
fcusage =3D {
fs =3D 0x0,
save_f_total_time =3D {
tv_sec =3D 0,
tv_usec =3D 0
},
save_total =3D {
tv_sec =3D 0,
tv_usec =3D 0
},
f_start =3D {
tv_sec =3D 0,
tv_usec =3D 0
}
}
rsinfo =3D {
type =3D T_ReturnSetInfo,
econtext =3D 0x1aedaf0,
expectedDesc =3D 0x1aee1e0,
allowedModes =3D 11,
returnMode =3D SFRM_ValuePerCall,
isDone =3D ExprSingleResult,
---Type <return> to continue, or q <return> to quit---
setResult =3D 0x0,
setDesc =3D 0x0
}
tmptup =3D {
t_len =3D 0,
t_self =3D {
ip_blkid =3D {
bi_hi =3D 0,
bi_lo =3D 0
},
ip_posid =3D 0
},
t_tableOid =3D 0,
t_data =3D 0x18d4b35
}
callerContext =3D 0x19bc3c8
oldcontext =3D <value optimized out>
direct_function_call =3D 1 '\001'
first_time =3D 1 '\001'
__func__ =3D "ExecMakeTableFunctionResult"
#6 0x0000000000599151 in FunctionNext (node=3D0x1aed9e0) at
nodeFunctionscan.c:65
slot =3D <value optimized out>
estate =3D <value optimized out>
direction =3D ForwardScanDirection
tuplestorestate =3D <value optimized out>
#7 0x0000000000588c3e in ExecScanFetch (node=3D0x1aed9e0,
accessMtd=3D0x5990e0 <FunctionNext>, recheckMtd=3D0x598e50
<FunctionRecheck>) at execScan.c:82
estate =3D <value optimized out>
#8 ExecScan (node=3D0x1aed9e0, accessMtd=3D0x5990e0 <FunctionNext>,
recheckMtd=3D0x598e50 <FunctionRecheck>) at execScan.c:132
econtext =3D 0x1aedaf0
qual =3D 0x0
projInfo =3D 0x0
isDone =3D <value optimized out>
resultSlot =3D <value optimized out>
#9 0x00000000005817f8 in ExecProcNode (node=3D0x1aed9e0) at
execProcnode.c:425
result =3D <value optimized out>
__func__ =3D "ExecProcNode"
#10 0x0000000000580722 in ExecutePlan (queryDesc=3D0x18d3990,
direction=3D<value optimized out>, count=3D0) at execMain.c:1395
slot =3D <value optimized out>
current_tuple_count =3D 0
#11 standard_ExecutorRun (queryDesc=3D0x18d3990, direction=3D<value
optimized out>, count=3D0) at execMain.c:303
estate =3D 0x1aed8d0
operation =3D CMD_SELECT
dest =3D 0x18c2f20
sendTuples =3D <value optimized out>
oldcontext =3D 0x19bc2b8
#12 0x00007eff57fb2a4b in pgss_ExecutorRun (queryDesc=3D0x18d3990,
direction=3DForwardScanDirection, count=3D0) at pg_stat_statements.c:719
save_exception_stack =3D 0x7fffa59cbe00
save_context_stack =3D 0x0
local_sigjmp_buf =3D {{
__jmpbuf =3D {25985856, 5106765649720642852, 25964320,
26032528, 1, 25964272, -5106611986443793116, -4962879123083490012},
__mask_was_saved =3D 0,
---Type <return> to continue, or q <return> to quit---
__saved_mask =3D {
__val =3D {5773925, 26032528, 28235984, 0, 25985856,
25964096, 5770657, 0, 28162928, 0, 25964320, 26032528, 1, 25964272,
7625096, 26782512}
}
}}
#13 0x00000000006568f7 in PortalRunSelect (portal=3D0x18c8340,
forward=3D<value optimized out>, count=3D0, dest=3D0x18c2f20) at pquery.c:9=
44
queryDesc =3D 0x18d3990
direction =3D ForwardScanDirection
nprocessed =3D <value optimized out>
__func__ =3D "PortalRunSelect"
#14 0x0000000000657b98 in PortalRun (portal=3D0x18c8340,
count=3D9223372036854775807, isTopLevel=3D1 '\001', dest=3D0x18c2f20,
altdest=3D0x18c2f20, completionTag=3D0x7fffa59cbf10 "") at pquery.c:788
save_exception_stack =3D 0x7fffa59cc050
save_context_stack =3D 0x0
local_sigjmp_buf =3D {{
__jmpbuf =3D {25964320, 5106769150708288804, 25985856,
26785952, 2, 25964272, -5106611986450084572, 5106765901172706596},
__mask_was_saved =3D 0,
__saved_mask =3D {
__val =3D {7493551, 25964272, 26715728, 9017635, 25985856,
9017635, 80, 25856832, 25985856, 26785952, 2, 25964272, 7570597,
8762301, 2, 26785680}
}
}}
result =3D <value optimized out>
nprocessed =3D <value optimized out>
saveTopTransactionResourceOwner =3D 0x197cff0
saveTopTransactionContext =3D 0x197cee0
saveActivePortal =3D 0x0
saveResourceOwner =3D 0x197cff0
savePortalContext =3D 0x0
saveMemoryContext =3D 0x197cee0
__func__ =3D "PortalRun"
#15 0x000000000065425b in exec_simple_query (query_string=3D0x198ab30 "
select * from test_test();") at postgres.c:1046
parsetree =3D 0x198b790
portal =3D 0x18c8340
snapshot_set =3D <value optimized out>
commandTag =3D <value optimized out>
completionTag =3D
"\000\000\000\000\377\177\000\000\024\370\237\245\377\177\000\000p\277\234\=
245\377\177\000\000\060K\215\001\000\000\000\000P\277\234\245\377\177\000\0=
00\024\370\237\245\377\177\000\000\220\277\234\245\377\177\000\000\200\301\=
234\245\377\177\000"
querytree_list =3D <value optimized out>
plantree_list =3D 0x18c2ef0
receiver =3D 0x18c2f20
format =3D 0
dest =3D DestRemote
oldcontext =3D 0x197cee0
parsetree_list =3D 0x198b8c0
parsetree_item =3D 0x198b8a0
save_log_statement_stats =3D 0 '\000'
was_logged =3D <value optimized out>
isTopLevel =3D <value optimized out>
msec_str =3D
"\034\000\000\000\000\000\000\000\060\253\230\001\000\000\000\000\001\000\0=
00\000\000\000\000\000\201\200\200\200\200\200\200\200"
__func__ =3D "exec_simple_query"
#16 0x00000000006550b0 in PostgresMain (argc=3D<value optimized out>,
argv=3D<value optimized out>, dbname=3D0x18aa4d0 "transport",
username=3D<value optimized out>) at postgres.c:3959
query_string =3D 0x198ab30 " select * from test_test();"
firstchar =3D <value optimized out>
---Type <return> to continue, or q <return> to quit---
input_message =3D {
data =3D 0x198ab30 " select * from test_test();",
len =3D 29,
maxlen =3D 1024,
cursor =3D 29
}
local_sigjmp_buf =3D {{
__jmpbuf =3D {140735971901792, 5106768996678765860, 1, 1,
-9187201950435737471, 0, -5106611986527679196, 5106765900793253156},
__mask_was_saved =3D 1,
__saved_mask =3D {
__val =3D {0, 0, 0, 0, 0, 139635321201376, 139635337349552,
0, 4294967295, 0, 1, 11688832, 0, 9259542123273814145, 13970, 0}
}
}}
send_ready_for_query =3D 0 '\000'
__func__ =3D "PostgresMain"
#17 0x0000000000611991 in BackendRun () at postmaster.c:3614
ac =3D 1
secs =3D 439980748
usecs =3D 431501
i =3D <value optimized out>
av =3D 0x18aa5e0
maxac =3D <value optimized out>
#18 BackendStartup () at postmaster.c:3304
bn =3D 0x18cf0a0
pid =3D 0
#19 ServerLoop () at postmaster.c:1367
rmask =3D {
fds_bits =3D {8, 0 <repeats 15 times>}
}
selres =3D <value optimized out>
readmask =3D {
fds_bits =3D {56, 0 <repeats 15 times>}
}
nSockets =3D 6
now =3D <value optimized out>
last_touch_time =3D 1386663421
__func__ =3D "ServerLoop"
#20 0x00000000006145a1 in PostmasterMain (argc=3D<value optimized out>,
argv=3D<value optimized out>) at postmaster.c:1127
opt =3D <value optimized out>
status =3D <value optimized out>
userDoption =3D <value optimized out>
listen_addr_saved =3D 1 '\001'
i =3D <value optimized out>
__func__ =3D "PostmasterMain"
#21 0x00000000005b3540 in main (argc=3D5, argv=3D0x18a7680) at main.c:199
Any thoughts?
--=20
Kind regards,
Sergey Konoplev
PostgreSQL Consultant and DBA
http://www.linkedin.com/in/grayhemp
+1 (415) 867-9984, +7 (901) 903-0499, +7 (988) 888-1979
gray.ru@gmail.com
