We are developing on and running Postgres 9.3.5 on FreeBsd 10.0-p12.
We have been experiencing a intermittent postgres core dump which
Seems primarily to be associated with the the 2 functions below.
The area of interest is based on the content of the postgres log file which
often indicates
2014-12-01T14:37:41.559725-05:00 puertorico local0 info postgres[30154]: [3-1]
LOG: server process (PID 30187) was terminated by signal 11: Segmentation fault
2014-12-01T14:37:41.559787-05:00 puertorico local0 info postgres[30154]: [3-2]
DETAIL: Failed process was running: SELECT * FROM
cc.get_port_and_registration_data($1, $2, $3, $4, $5)
2014-12-01T14:37:41.559794-05:00 puertorico local0 info postgres[30154]: [4-1]
LOG: terminating any other active server processes
And that the core file back trace may show association to perl libraries of
which we only have two possibilities currently, and this is the most relevant
logic.
Given the onset of this problem, we suspect it has something to do with the
addition of DNS lookup within the our perlu function cc.get_sip_id(...).
I would note that we have captured the details of the arguments to the
cc.get_port_and_registration_data at time of a core and can repeat
the same query after the core event without incident. Currently we are testing
for an absence of the core event by commenting out dns perl function logic and
have rebuilt postgres with debugging symbols. An example core of this output
is below. ( prior to function alteration ).
I am usually attempting to debug simpler program errors without such a bad
impact on the postgres server.
I would appreciate any comment on potential issues or bad practices in the
suspect functions and/or additional details
that could be gathered from the core files that might assist in resolving this
matter.
Thanks
Dave Day
CREATE OR REPLACE FUNCTION cc.get_port_and_registration_data(cca character
varying, tgrp character varying, dhost character varying, usr character
varying[], orig_flag boolean)
RETURNS SETOF cc.port_type_tbl AS
$BODY$
-- The inputs to this overloaded function are sip parameters.
DECLARE pid INTEGER;
DECLARE uid INTEGER;
DECLARE mode CHARACTER VARYING;
DECLARE sql_result record;
BEGIN
SELECT * FROM cc.get_sip_id($1,$2,$3, $4) INTO pid LIMIT 1; -- Perl
invocation
FOR sql_result IN
SELECT cc.get_db_refhndl($5)AS db_ref_hndl,* FROM cc.port_info t1
LEFT JOIN (SELECT translator_id, mgcp_digit_map FROM
cc.translator_sys) t2 USING (translator_id)
LEFT JOIN cc.register_port USING (port_id)
WHERE port_id = pid AND op_mode = 'default'
ORDER by expiration DESC
LOOP
RETURN NEXT sql_result;
END LOOP;
RETURN;
END;
$BODY$
LANGUAGE plpgsql VOLATILE
COST 100
ROWS 1000;
ALTER FUNCTION cc.get_port_and_registration_data(character varying, character
varying, character varying, character varying[], boolean)
OWNER TO redcom;
CREATE OR REPLACE FUNCTION cc.get_sip_id(cca character varying, tgrp character
varying, dhost character varying, usr character varying[])
RETURNS integer AS
$BODY$
use Socket qw(getaddrinfo getnameinfo
PF_UNSPEC SOCK_STREAM AI_NUMERICHOST NI_NAMEREQD NIx_NOSERV);
use URI;
sub is_local {
my $host = shift(@_);
my $result = 0;
open my $fh, "/sbin/route get $host |";
while (<$fh>) {
if (m/interface/) {
chomp;
my @fields = split /\s+/;
if ($fields[2] eq "lo0") {
$result = 1;
}
last;
}
}
close $fh;
return $result;
}
my ($cca, $tgrp, $dhost, $usr) = @_;
$do_dns_lookup = 1;
{
my $query = qq{
SELECT sip_dns_lookup_on_incoming_requests FROM admin.system_options;
};
my $rv = spi_exec_query($query, 1);
if ($rv->{status} =~ /^SPI_OK/ && $rv->{processed} > 0) {
$do_dns_lookup = $rv->{rows}[0]->{sip_dns_lookup_on_incoming_requests};
}
}
if ($tgrp ne '') {
my $query = qq{
SELECT port_id FROM cc.port_info WHERE destination_group_id = '$tgrp';
};
my $rv = spi_exec_query($query, 1);
if ($rv->{status} =~ /^SPI_OK/ && $rv->{processed} > 0) {
return $rv->{rows}[0]->{port_id};
}
}
if ($cca ne '') {
my $query = qq{
SELECT port_id FROM cc.port_info WHERE call_control_agent = '$cca';
};
my $rv = spi_exec_query($query, 1);
if ($rv->{status} =~ /^SPI_OK/ && $rv->{processed} > 0) {
return $rv->{rows}[0]->{port_id};
}
}
for my $uristr (@$usr) {
if ($uristr ne '') {
my $uri = URI->new($uristr);
if (is_local($uri->host)) {
$dhost = '';
my $name = $uri->user;
if ($name ne '') {
my $query = qq{
SELECT port_id FROM cc.port_info
WHERE registration_user = '$name';
};
my $rv = spi_exec_query($query, 1);
if ($rv->{status} =~ /^SPI_OK/ && $rv->{processed} > 0) {
return $rv->{rows}[0]->{port_id};
}
}
}
}
}
if ($dhost ne '') {
$pattern = "[:@]" . quotemeta($dhost) . "(?::\\\d+)?(?:;.*)?\$";
my $query = qq{
SELECT port_id FROM cc.port_info
WHERE port_address ~* '$pattern';
};
my $rv = spi_exec_query($query, 1);
if ($rv->{status} =~ /^SPI_OK/ && $rv->{processed} > 0) {
return $rv->{rows}[0]->{port_id};
}
if ($do_dns_lookup) {
my %hints = (family => PF_UNSPEC, socktype => SOCK_STREAM, flags =>
AI_NUMERICHOST);
$dhost_trimmed = ($dhost =~ m/\[(.*)\]/) ? $1 : $dhost;
my ($err, @result) = getaddrinfo($dhost_trimmed, "", \%hints);
if ($err == 0) {
for my $ai (@result) {
my ($err, $hostname) = getnameinfo($ai->{addr}, NI_NAMEREQD,
NIx_NOSERV);
if ($err == 0 && $hostname ne '') {
$pattern = "[:@]" . quotemeta($hostname) .
"(?::\\\d+)?(?:;.*)?\$";
my $query = qq{
SELECT port_id FROM cc.port_info
WHERE port_address ~* '$pattern';
};
my $rv = spi_exec_query($query , 1);
if ($rv->{status} =~ /^SPI_OK/ && $rv->{processed} > 0) {
return $rv->{rows}[0]->{port_id};
}
}
}
}
} else {
if ($dhost eq "127.0.0.1") {
$pattern = "[:@]localhost(?::\\\d+)?(?:;.*)?\$";
my $query = qq{
SELECT port_id FROM cc.port_info
WHERE port_address ~* '$pattern';
};
my $rv = spi_exec_query($query , 1);
if ($rv->{status} =~ /^SPI_OK/ && $rv->{processed} > 0) {
return $rv->{rows}[0]->{port_id};
}
}
}
}
for my $uristr (@$usr) {
if ($uristr ne '') {
my $uri = URI->new($uristr);
my $name = $uri->user;
if ($name ne '') {
my $query = qq{
SELECT port_id FROM cc.port_info
WHERE registration_user = '$name';
};
my $rv = spi_exec_query($query, 1);
if ($rv->{status} =~ /^SPI_OK/ && $rv->{processed} > 0) {
return $rv->{rows}[0]->{port_id};
}
}
}
}
return 0;
$BODY$
LANGUAGE plperlu VOLATILE
COST 100;
ALTER FUNCTION cc.get_sip_id(character varying, character varying, character
varying, character varying[])
OWNER TO redcom;
[cid:image001.gif@01D00E37.901352C0]<http://engweb/mantis/file_download.php?file_id=6488&type=bug>
georgia_core_3.txt<http://engweb/mantis/file_download.php?file_id=6488&type=bug>
(11,088 bytes) 2014-12-01 11:27
(gdb) bt full
#0 0x00000000006f50b0 in spg_range_quad_picksplit (fcinfo=<optimized out>) at
rangetypes_spgist.c:233
empty = 0 '\000'
empty = 0 '\000'
in = 0xf93a1
typcache = 0x0
i = <error reading variable i (Cannot access memory at address 0x0)>
nonEmptyCount = <optimized out>
centroid = <optimized out>
#1 0x0000000000705681 in perform_relmap_update (updates=<optimized out>,
shared=0 '\000') at relmapper.c:842
newmap = {magic = 7296347, num_mappings = 0, mappings = {{mapoid =
4294948304, mapfilenode = 32767}, {mapoid = 2679032113, mapfilenode = 0},
{mapoid = 4294948336, mapfilenode = 32767}, {
mapoid = 7296186, mapfilenode = 0}, {mapoid = 0, mapfilenode =
0}, {mapoid = 43286576, mapfilenode = 8}, {mapoid = 4294948400, mapfilenode =
32767}, {mapoid = 0, mapfilenode = 0}, {
mapoid = 4294948736, mapfilenode = 32767}, {mapoid = 7295065,
mapfilenode = 0}, {mapoid = 4294967294, mapfilenode = 0}, {mapoid = 43297248,
mapfilenode = 8}, {mapoid = 640,
mapfilenode = 0}, {mapoid = 43297240, mapfilenode = 8}, {mapoid =
4088945280, mapfilenode = 0}, {mapoid = 218805760, mapfilenode = 8}, {mapoid =
0, mapfilenode = 196609}, {
mapoid = 0, mapfilenode = 0}, {mapoid = 6913104, mapfilenode =
0}, {mapoid = 184, mapfilenode = 65538}, {mapoid = 2, mapfilenode = 0}, {mapoid
= 0, mapfilenode = 0}, {
mapoid = 42547296, mapfilenode = 8}, {mapoid = 0, mapfilenode =
0}, {mapoid = 1020833, mapfilenode = 0}, {mapoid = 0, mapfilenode = 196610},
{mapoid = 0, mapfilenode = 0}, {
mapoid = 6824176, mapfilenode = 0}, {mapoid = 63, mapfilenode =
65538}, {mapoid = 2, mapfilenode = 0}, {mapoid = 0, mapfilenode = 0}, {mapoid =
42547296, mapfilenode = 8}, {
mapoid = 0, mapfilenode = 0}, {mapoid = 15, mapfilenode = 0},
{mapoid = 0, mapfilenode = 196611}, {mapoid = 0, mapfilenode = 0}, {mapoid =
6698992, mapfilenode = 0}, {mapoid = 60,
mapfilenode = 65538}, {mapoid = 2, mapfilenode = 0}, {mapoid = 0,
mapfilenode = 0}, {mapoid = 42547296, mapfilenode = 8}, {mapoid = 0,
mapfilenode = 0} <repeats 11 times>, {
mapoid = 4294967295, mapfilenode = 0}, {mapoid = 218817224,
mapfilenode = 8}, {mapoid = 218805768, mapfilenode = 8}, {mapoid = 22,
mapfilenode = 0}, {mapoid = 15, mapfilenode = 0}, {
mapoid = 1020833, mapfilenode = 0}, {mapoid = 4294948784,
mapfilenode = 32767}, {mapoid = 7362177, mapfilenode = 0}, {mapoid = 0,
mapfilenode = 0}, {mapoid = 218817224,
mapfilenode = 8}}, crc = 226, pad = 0}
#2 AtEOXact_RelationMap (isCommit=<optimized out>) at relmapper.c:423
No locals.
#3 0x00000000005c3fe0 in cost_merge_append (path=0x80d0ae318, root=0xda8e0956,
pathkeys=0xe02190c4, n_streams=<optimized out>,
input_startup_cost=6.9533558069622868e-310,
input_total_cost=1.7084015800703071e-313, tuples=6.9533558069255283e-310)
at costsize.c:1383
run_cost = <optimized out>
startup_cost = <optimized out>
N = 1.6996756523143625e-313
comparison_cost = <optimized out>
logN = <optimized out>
#4 0x00000000005c3f30 in cost_sort (path=0xf, root=0xda8e0956,
pathkeys=0xe02190c4, input_cost=<optimized out>, tuples=<optimized out>,
width=<optimized out>, comparison_cost=<optimized out>,
sort_mem=<optimized out>, limit_tuples=<optimized out>) at costsize.c:1303
mergeorder = 0
npageaccesses = <optimized out>
nruns = <optimized out>
startup_cost = 1.6996987484999217e-313
run_cost = <optimized out>
input_bytes = <optimized out>
output_bytes = <optimized out>
sort_mem_bytes = <optimized out>
#5 0x00000000005bf6d3 in remove_gene (root=<optimized out>, gene=<optimized
out>, edge=..., edge_table=<optimized out>) at geqo_erx.c:257
possess_edge = <optimized out>
genes_remaining = -534671164
#6 gimme_tour (root=0x7fffffffbb00, edge_table=0x16, new_gene=0x100000001,
num_gene=1020833) at geqo_erx.c:208
edge_failures = <error reading variable edge_failures (Cannot access
memory at address 0x0)>
#7 0x00000000005be515 in copyParamList (from=0x1) at params.c:69
typLen = 0
typLen = 0
oprm = 0x80294a9d8
typByVal = 127 '\177'
typByVal = 127 '\177'
nprm = 0x80d0903a8
size = <optimized out>
retval = 0x80d0903a8
i = <error reading variable i (Cannot access memory at address 0x0)>
#8 0x00000000005d6d1e in create_lateral_join_info (root=0x80d0abd58) at
initsplan.c:547
brel = 0x7
lateral_referencers = <optimized out>
lc = <optimized out>
rti = <optimized out>
#9 0x00000000005d8b83 in query_planner (root=0x0, tlist=0x802ba2120,
tuple_fraction=3.0451286481687515e-317, limit_tuples=0,
qp_callback=0x7fffffffbbd0, qp_extra=0x80d0ab2f0,
cheapest_path=0x80d0ab390, sorted_path=0x80d0ab358, num_groups=<optimized
out>) at planmain.c:128
parse = 0x80d090718
joinlist = <optimized out>
total_pages = <optimized out>
final_rel = <optimized out>
cheapestpath = <optimized out>
sortedpath = <optimized out>
#10 0x00000000005d7c54 in distribute_qual_to_rels (root=0x80d0903a8,
clause=0x802ba2120, is_deduced=0 '\000', below_outer_join=8 '\b', jointype=8,
qualscope=0x802ba2120, ojscope=0x0,
outerjoin_nonnullable=<optimized out>, deduced_nullable_relids=<optimized
out>, postponed_qual_list=<optimized out>) at initsplan.c:1379
relids = 0x802a00a68
nullable_relids = 0x60
relids = 0x802a00a68
relids = 0x802a00a68
relids = 0x802a00a68
relids = 0x802a00a68
relids = 0x802a00a68
nullable_relids = 0x60
pseudoconstant = <error reading variable pseudoconstant (Cannot access
memory at address 0x0)>
maybe_equivalence = <optimized out>
outerjoin_delayed = <optimized out>
restrictinfo = <optimized out>
#11 0x00000000005d705b in deconstruct_recurse (root=0x802a00a68, jtnode=0x0,
below_outer_join=8 '\b', qualscope=0x0, inner_join_rels=0x802a00a68,
postponed_qual_list=0x60) at initsplan.c:744
sub_qualscope = 0x802ba2120
sub_qualscope = 0x802ba2120
sub_joinlist = 0x802a00a68
sub_members = <optimized out>
child_postponed_quals = 0x802b96080
l = <optimized out>
joinlist = <optimized out>
#12 0x000000000063ebed in mdtruncate (reln=<optimized out>, forknum=32767,
nblocks=0) at md.c:921
lastsegblocks = <optimized out>
ov = <optimized out>
curnblk = <optimized out>
v = <optimized out>
#13 0x000000000063ecab in mdpostckpt () at md.c:1287
absorb_counter = <optimized out>
#14 0x00000000006f88b5 in SearchCatCache (cache=0x63ebed <mdtruncate+461>,
v1=<optimized out>, v2=<optimized out>, v3=<optimized out>, v4=140737488338336)
at catcache.c:1117
__atp = <optimized out>
__test = <optimized out>
__isnull = 0 '\000'
__isnull = 0 '\000'
__isnull = 0 '\000'
__cur_keys = 0x802ba2120
__cur_nkeys = <optimized out>
cur_skey = {{sk_flags = 45752608, sk_attno = 8, sk_strategy = 0,
sk_subtype = 218892072, sk_collation = 8, sk_func = {fn_addr = 0x60, fn_oid =
96, fn_nargs = 0, fn_strict = 0 '\000',
fn_retset = 0 '\000', fn_stats = 104 'h', fn_extra = 0x0, fn_mcxt
= 0x802a00a68, fn_expr = 0x0}, sk_argument = 34403781224}, {sk_flags =
218694424, sk_attno = 8, sk_strategy = 0,
sk_subtype = 0, sk_collation = 0, sk_func = {fn_addr = 0x0, fn_oid
= 4294950464, fn_nargs = 32767, fn_strict = 0 '\000', fn_retset = 0 '\000',
fn_stats = 91 '[',
fn_extra = 0x802b96830, fn_mcxt = 0x802ba2120, fn_expr =
0x802b96080}, sk_argument = 0}, {sk_flags = 45752608, sk_attno = 8, sk_strategy
= 0, sk_subtype = 0, sk_collation = 0,
sk_func = {fn_addr = 0x802a00a68, fn_oid = 0, fn_nargs = 0,
fn_strict = 0 '\000', fn_retset = 0 '\000', fn_stats = 112 'p', fn_extra =
0x63ebed <mdtruncate+461>,
fn_mcxt = 0x802ba2030, fn_expr = 0x0}, sk_argument =
34403781224}, {sk_flags = 0, sk_attno = 0, sk_strategy = 0, sk_subtype =
4294950560, sk_collation = 32767, sk_func = {
fn_addr = 0x63ecab <mdpostckpt+11>, fn_oid = 45752432, fn_nargs =
8, fn_strict = 0 '\000', fn_retset = 0 '\000', fn_stats = 0 '\000', fn_extra =
0x802a00a68, fn_mcxt = 0x802b94830,
fn_expr = 0x7fffffffbee0}, sk_argument = 7309493}}
hashValue = 4294950304
hashIndex = 218892072
bucket = 0x802b94830
relation = <optimized out>
scandesc = <optimized out>
ntp = <optimized out>
ct = <optimized out>
#15 0x00000000006f835f in InitCatCache (id=-19952, reloid=3666741590,
indexoid=3760296132, nkeys=43297240, key=0x7ff7fd6b3590, nbuckets=218838980) at
catcache.c:730
oldcxt = 0x802a00a68
#16 0x000000000059329c in _SPI_execute_plan (plan=0x802b94800,
paramLI=0x802b94830, snapshot=<optimized out>, crosscheck_snapshot=0x802a00a01,
read_only=0 '\000', fire_triggers=<optimized out>,
tcount=<optimized out>) at spi.c:2194
completionTag =
"\240\277\377\377\377\177\000\000\234\062Y\000\000\000\000\000\060l\271\002\b\000\000\000\060H\271\002\b\000\000\000x\v\240\002\000\000\000\000h\n\240\002\b\000\000\000p\302
\377\377\377\177\000\000@=Y\000\000\000\000"
canSetTag = <optimized out>
dest = <optimized out>
stmt_list = <optimized out>
lc2 = <optimized out>
spierrcontext = {previous = 0x8029f7140, callback = 0x80bc09448, arg =
0x802a00a68}
spierrcontext = {previous = 0x8029f7140, callback = 0x80bc09448, arg =
0x802a00a68}
my_res = <error reading variable my_res (Cannot access memory at
address 0xe)>
my_processed = <error reading variable my_processed (Cannot access
memory at address 0x0)>
my_lastoid = <error reading variable my_lastoid (Cannot access memory
at address 0x0)>
res = <error reading variable res (Cannot access memory at address 0x0)>
pushed_active_snap = <error reading variable pushed_active_snap (Cannot
access memory at address 0x0)>
my_tuptable = <optimized out>
cplan = 0x0
lc1 = <optimized out>
#17 0x000000080b9078c5 in ?? ()
No symbol table info available.
#18 0x000000080b9083d0 in ?? ()
No symbol table info available.
#19 0x000000080bc09a00 in ?? ()
No symbol table info available.
#20 0x00007fffffffc288 in ?? ()
No symbol table info available.
#21 0x000000080bc09a70 in ?? ()
No symbol table info available.
#22 0x000000080bc098f8 in ?? ()
No symbol table info available.
#23 0x00007fffffffc288 in ?? ()
No symbol table info available.
#24 0x00007fffffffc150 in ?? ()
No symbol table info available.
#25 0x000000080b9083e5 in ?? ()
No symbol table info available.
#26 0x0000000000000000 in ?? ()
No symbol table info available.
