segmentation fault postgres 9.3.5 core dump perlu related ?

From: "Day, David" <dday(at)redcom(dot)com>
To: "pgsql-general(at)postgresql(dot)org" <pgsql-general(at)postgresql(dot)org>
Subject: segmentation fault postgres 9.3.5 core dump perlu related ?
Date: 2014-12-02 19:16:13
Message-ID: 401084E5E73F4241A44F3C9E6FD7942801124A3144@exch-01
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-general

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(dot)gif(at)01D00E37(dot)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(at)=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.

Responses

Browse pgsql-general by date

  From Date Subject
Next Message Adrian Klaver 2014-12-02 20:25:20 Re: Programmatic access to interval units
Previous Message Nelson Green 2014-12-02 18:40:37 Re: Programmatic access to interval units