On Tue, Jan 24, 2012 at 12:43 AM, Tom Lane <t...@sss.pgh.pa.us> wrote:
> Phil Sorber <p...@omniti.com> writes:
>> I've attached a backtrace.
>
> How about a test case? I have no faith in the proposed patch without
> some evidence of what it's supposed to fix.
We are having trouble coming up with a test case that can reliably
reproduce this. I has happened 5 times since Friday. There was another
one this morning and we have more logging turned on now and I have
attached more information. Is there anything else we can do to help
debug it? This is a production machine and we may be forced into
applying the patch we came up with, but we wanted to have as good of a
solution as possible.
>
> regards, tom lane
I have a new backtrace which is almost identical to the old one. Only
memory addresses differ. I am attaching it anyway. I am also attaching
the pertinent logs with sensitive information changed. The log lines
are just the entries for the PID that segfaulted from right before it
happened. The PID was long lived but nothing was going on for minutes
of time before the segfault. I am also attaching the source of the
function that was called right before the segfault. Again with
sensitive information changed.
Thanks.
#0 ExecGetResultType (planstate=0x0) at execUtils.c:479
#1 0x00000000005893d9 in ExecInitCteScan (node=0x1445ed0, estate=0x13a3f80,
eflags=<value optimized out>) at nodeCtescan.c:259
#2 0x0000000000570f75 in ExecInitNode (node=0x0, estate=0x13a3f80,
eflags=20595792)
at execProcnode.c:227
#3 0x000000000056e564 in EvalPlanQualStart (epqstate=0x135fd20,
parentestate=<value optimized out>) at execMain.c:2293
#4 EvalPlanQualBegin (epqstate=0x135fd20, parentestate=<value optimized out>)
at execMain.c:2144
#5 0x000000000056ec96 in EvalPlanQual (estate=0x135e990, epqstate=0x135fd20,
relation=<value optimized out>, rti=3, tid=0x7fff46ea4630,
priorXmax=<value optimized out>) at execMain.c:1710
#6 0x0000000000586e91 in ExecUpdate (node=0x135fc80) at nodeModifyTable.c:587
#7 ExecModifyTable (node=0x135fc80) at nodeModifyTable.c:838
#8 0x0000000000570d98 in ExecProcNode (node=0x135fc80) at execProcnode.c:371
#9 0x000000000058956c in CteScanNext (node=0x13dcfa0) at nodeCtescan.c:103
#10 0x0000000000577fce in ExecScanFetch (node=0x13dcfa0,
accessMtd=<value optimized out>, recheckMtd=<value optimized out>) at
execScan.c:82
#11 ExecScan (node=0x13dcfa0, accessMtd=<value optimized out>,
recheckMtd=<value optimized out>) at execScan.c:167
#12 0x0000000000570ce8 in ExecProcNode (node=0x13dcfa0) at execProcnode.c:424
#13 0x000000000058a835 in ExecSetParamPlan (node=0x141a1b0, econtext=0x14156d0)
at nodeSubplan.c:922
#14 0x0000000000576bd7 in ExecEvalParamExec (exprstate=<value optimized out>,
econtext=0x1a30, isNull=0x7fff46ea481f "", isDone=0x1) at execQual.c:990
#15 0x00000000005710cc in ExecEvalNot (notclause=<value optimized out>,
econtext=0x1a30, isNull=0x7fff46ea481f "", isDone=<value optimized out>)
at execQual.c:2566
#16 0x00000000005715df in ExecQual (qual=<value optimized out>,
econtext=0x14156d0,
resultForNull=0 '\000') at execQual.c:5006
#17 0x0000000000587fe6 in ExecResult (node=0x14155c0) at nodeResult.c:82
#18 0x0000000000570da8 in ExecProcNode (node=0x14155c0) at execProcnode.c:367
#19 0x0000000000577fce in ExecScanFetch (node=0x13dfef8,
accessMtd=<value optimized out>, recheckMtd=<value optimized out>) at
execScan.c:82
#20 ExecScan (node=0x13dfef8, accessMtd=<value optimized out>,
recheckMtd=<value optimized out>) at execScan.c:167
#21 0x0000000000570d18 in ExecProcNode (node=0x13dfef8) at execProcnode.c:412
#22 0x000000000058653e in ExecModifyTable (node=0x13df5e8) at
nodeModifyTable.c:765
#23 0x0000000000570d98 in ExecProcNode (node=0x13df5e8) at execProcnode.c:371
#24 0x000000000056fc32 in ExecutePlan (queryDesc=0x13b7290, direction=6704,
count=0)
at execMain.c:1439
#25 standard_ExecutorRun (queryDesc=0x13b7290, direction=6704, count=0)
at execMain.c:313
#26 0x00007f386af2a68b in explain_ExecutorRun (queryDesc=<value optimized out>,
direction=<value optimized out>, count=<value optimized out>) at
auto_explain.c:214
#27 0x00000000005913f1 in _SPI_pquery (plan=<value optimized out>,
paramLI=<value optimized out>, snapshot=<value optimized out>,
crosscheck_snapshot=<value optimized out>, read_only=0 '\000',
fire_triggers=<value optimized out>, tcount=<value optimized out>) at
spi.c:2110
#28 _SPI_execute_plan (plan=<value optimized out>, paramLI=<value optimized
out>,
snapshot=<value optimized out>, crosscheck_snapshot=<value optimized out>,
read_only=0 '\000', fire_triggers=<value optimized out>,
tcount=<value optimized out>) at spi.c:1922
#29 0x00000000005917ac in SPI_execute_plan_with_paramlist (plan=0x1395240,
params=<value optimized out>, read_only=0 '\000', tcount=<value optimized
out>)
at spi.c:423
#30 0x00007f36ddb6f9dd in exec_stmt_execsql (estate=0x7fff46ea4f70,
stmt=0x1386250)
at pl_exec.c:3036
#31 0x00007f36ddb71c6e in exec_stmt (estate=0x7fff46ea4f70, stmts=<value
optimized out>)
at pl_exec.c:1342
#32 exec_stmts (estate=0x7fff46ea4f70, stmts=<value optimized out>) at
pl_exec.c:1241
#33 0x00007f36ddb7330f in exec_stmt_block (estate=<value optimized out>,
block=<value optimized out>) at pl_exec.c:1179
#34 0x00007f36ddb73e82 in plpgsql_exec_function (func=0x1315bd0,
fcinfo=0x13936b0)
at pl_exec.c:319
#35 0x00007f36ddb68f33 in plpgsql_call_handler (fcinfo=<value optimized out>)
at pl_handler.c:122
#36 0x00000000006fd6c9 in fmgr_security_definer (fcinfo=<value optimized out>)
at fmgr.c:968
#37 0x00000000005762bd in ExecMakeFunctionResult (fcache=0x1393640,
econtext=<value optimized out>, isNull=0x1394958 "", isDone=<value
optimized out>)
at execQual.c:1824
#38 0x00000000005717d6 in ExecTargetList (projInfo=<value optimized out>,
isDone=<value optimized out>) at execQual.c:5104
#39 ExecProject (projInfo=<value optimized out>, isDone=<value optimized out>)
at execQual.c:5319
#40 0x0000000000587f9b in ExecResult (node=0x1393340) at nodeResult.c:155
#41 0x0000000000570da8 in ExecProcNode (node=0x1393340) at execProcnode.c:367
#42 0x000000000056fc32 in ExecutePlan (queryDesc=0x13e4b10, direction=6704,
count=0)
at execMain.c:1439
#43 standard_ExecutorRun (queryDesc=0x13e4b10, direction=6704, count=0)
at execMain.c:313
#44 0x00007f386af2a68b in explain_ExecutorRun (queryDesc=<value optimized out>,
direction=<value optimized out>, count=<value optimized out>) at
auto_explain.c:214
#45 0x000000000063c047 in PortalRunSelect (portal=0x1367180,
forward=<value optimized out>, count=0, dest=0x122cf50) at pquery.c:943
#46 0x000000000063d368 in PortalRun (portal=<value optimized out>,
count=<value optimized out>, isTopLevel=<value optimized out>,
dest=<value optimized out>, altdest=<value optimized out>,
completionTag=<value optimized out>) at pquery.c:787
#47 0x000000000063ad13 in exec_execute_message (argc=<value optimized out>,
argv=<value optimized out>, username=<value optimized out>) at
postgres.c:1963
#48 PostgresMain (argc=<value optimized out>, argv=<value optimized out>,
username=<value optimized out>) at postgres.c:3983
#49 0x00000000005fc289 in BackendRun () at postmaster.c:3601
#50 BackendStartup () at postmaster.c:3286
#51 ServerLoop () at postmaster.c:1455
#52 0x00000000005fe9cc in PostmasterMain (argc=3, argv=0x1226400) at
postmaster.c:1116
#53 0x000000000059fcc0 in main (argc=3, argv=0x12263f0) at main.c:199
2012-01-24 09:21:51.824 EST 127.0.0.1(44413) 31067 myuser myschema LOG:
execute <unnamed>: select user_data_ups( $1::uuid, $2::timestamp with time
zone, $3::text, $4::text, $5::text, $6::text, $7::date, $8::smallint, $9::text,
$10::text, $11::text, $12::text, $13::text, $14::text, $15::text, $16::integer,
$17::boolean, $18::boolean, $19::boolean, $20::boolean, $21::boolean,
$22::boolean, $23::boolean, $24::boolean, $25::boolean, $26::double precision,
$27::boolean, $28::boolean, $29::boolean, $30::text)
2012-01-24 09:21:51.824 EST 127.0.0.1(44413) 31067 myuser myschema DETAIL:
parameters: $1 = '8a99330a-3525-48ae-89b9-28a229575ba4', $2 = '2012-01-24
09:21:51-05', $3 = 'u...@example.com', $4 =
'a94293fefad8d8e1099ed368d60c11b3bb68c86743d9c9f2b99e0d8649927519', $5 =
'ad058d4471a774c752526b0b951c784a3e85b5f7a7d335d25eadbb94fca83834', $6 = 'User
Name', $7 = '1979-12-08', $8 = '2', $9 = '101 Lake Street Apt 12', $10 =
'Upstate', $11 = 'NY', $12 = '12345', $13 = '', $14 = '', $15 = '', $16 = NULL,
$17 = 'f', $18 = 'f', $19 = 't', $20 = 't', $21 = 't', $22 = 't', $23 = 't',
$24 = 't', $25 = 't', $26 = '1327334839', $27 = 'f', $28 = 't', $29 = 't', $30
= NULL
2012-01-24 09:22:02.870 EST 31549 LOG: server process (PID 31067) was
terminated by signal 11: Segmentation fault
CREATE OR REPLACE FUNCTION myschema.user_data_ups(uuid, timestamp with time
zone, text, text, text, text, date, smallint, text, text, text, text, text,
text, text, integer, boolean, boolean, boolean, boolean, boolean, boolean,
boolean, boolean, boolean, double precision, boolean, boolean, boolean, text)
RETURNS void
LANGUAGE plpgsql
SECURITY DEFINER
AS $function$
BEGIN
WITH upsert AS
(UPDATE
user_data
SET
last_update = $2::timestamp with time zone,
email_address = $3::text,
password_salt = $4::text,
password_hash = $5::text,
display_name = $6::text,
dob = $7::date,
gender = $8::smallint,
city = $10::text,
state = $11::text,
street_address = $9::text,
zipcode = $12::text,
profile_photo = $13::text,
ptp = $14::text,
ftp = $15::text,
grv = $16::integer,
pp = $17::boolean,
gr = $18::boolean,
nes = $19::boolean,
np = $20::boolean,
nnf = $21::boolean,
nbc = $22::boolean,
nnr = $23::boolean,
nsr = $24::boolean,
nws = $25::boolean,
signup_date = coalesce(to_timestamp($26::double
precision)::timestamp at time zone 'GMT',transaction_timestamp()),
uhc = $27::boolean,
email_verified = coalesce($28::boolean, false::boolean),
active = $29::boolean,
code = $30::text
WHERE
user_guid = $1::uuid
RETURNING
user_guid)
INSERT INTO
user_data (user_guid,
last_update,
email_address,
password_salt,
password_hash,
display_name,
dob,
gender,
street_address,
city,
state,
zipcode,
profile_photo,
ptp,
ftp,
grv,
pp,
gr,
nes,
np,
nnf,
nbc,
nnr,
nsr,
nws,
signup_date,
uhc,
email_verified,
active,
code)
SELECT
$1::uuid,
$2::timestamp with time zone,
$3::text,
$4::text,
$5::text,
$6::text,
$7::date,
$8::smallint,
$9::text,
$10::text,
$11::text,
$12::text,
$13::text,
$14::text,
$15::text,
$16::integer,
$17::boolean,
$18::boolean,
$19::boolean,
$20::boolean,
$21::boolean,
$22::boolean,
$23::boolean,
$24::boolean,
$25::boolean,
coalesce(to_timestamp($26::double precision)::timestamp at time zone
'GMT',transaction_timestamp()),
$27::boolean,
coalesce($28::boolean, false::boolean),
$29::boolean,
$30::text
WHERE
NOT EXISTS
(SELECT
true
FROM
upsert);
-- EXCEPTION
-- WHEN unique_violation THEN
-- RAISE LOG 'UNIQUE KEY VIOLATION FOR user_guid %', $1;
-- WHEN foreign_key_violation THEN
-- RAISE LOG 'FOREIGN KEY VIOLATION FOR user_guid %', $1;
-- WHEN not_null_violation THEN
-- RAISE LOG 'NOT NULL VIOLATION FOR user_guid %', $1;
-- WHEN check_violation THEN
-- RAISE LOG 'CHECK VIOLATION FOR user_guid %', $1;
END;
$function$
--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs
