cache lookup failed for function 1 on fmgr_info_cxt_security, fmgr.c:184

Soni <diptatapa@gmail.com> writes:

When "create extension "uuid-ossp"", I got :
2019-04-22 02:41:53.323 UTC [10305] XX000ERROR:  XX000: cache lookup
failed for function 1
2019-04-22 02:41:53.323 UTC [10305] XX000LOCATION:
fmgr_info_cxt_security, fmgr.c:184
2019-04-22 02:41:53.323 UTC [10305] XX000STATEMENT:  create extension
"uuid-ossp" ;

That is just bizarre. uuid-ossp's installation script does nothing
beyond a few simple CREATE FUNCTION commands, so it's really hard to
see how you could be getting to an incorrect function call.

Do you perhaps have any other extensions installed that could be
running add-on code during DDL commands? I'm thinking of pgaudit
or auto_explain or the like. If so, try disabling those to see
if the problem goes away.

If that's not it, could we trouble you to get a stack trace of
this problem? Set a breakpoint at errfinish, run the CREATE
EXTENSION, and when it stops send us the output of "bt".
(Make sure that fmgr_info_cxt_security appears one or two levels
down in the trace, else you stopped at the wrong message output.)

https://wiki.postgresql.org/wiki/Generating_a_stack_trace_of_a_PostgreSQL_backend

regards, tom lane

On 4/21/19 9:14 PM, Soni wrote:

Hello All,

CentOS Linux release 7.5.1804 (Core)
Postgres 10.7.

When "create extension "uuid-ossp"", I got :
2019-04-22 02:41:53.323 UTC [10305] XX000ERROR:  XX000: cache lookup
failed for function 1
2019-04-22 02:41:53.323 UTC [10305] XX000LOCATION:
fmgr_info_cxt_security, fmgr.c:184
2019-04-22 02:41:53.323 UTC [10305] XX000STATEMENT:  create extension
"uuid-ossp" ;
I tried reinstall contrib module and even all postgres component, but
still no luck.
Try restarting the server also but no luck.
Any idea how to resolve this ?

How and where are you installing Postgres and -contrib from?

Is the user you are running CREATE EXTENSION a superuser?

Thanks,
Soni

--
Adrian Klaver
adrian.klaver@aklaver.com

I install the contrib module from the postgres repo using yum install.
creating extension run as postgres superuser.

Thanks,
Soni

We have no other extensions installed, just plpgsql.
Here's the backtrace. Please let me know if it helps.

#0  errfinish (dummy=dummy@entry=0) at elog.c:414
#1  0x0000000000820068 in elog_finish (elevel=elevel@entry=20,
fmt=fmt@entry=0x864278 "cache lookup failed for function %u") at elog.c:1376
#2  0x0000000000821e63 in fmgr_info_cxt_security (functionId=1,
functionId@entry=18230952, finfo=finfo@entry=0x7ffcd9090460,
mcxt=<optimized out>,
    ignore_security=ignore_security@entry=0 '\000') at fmgr.c:184
#3  0x00000000008233f2 in fmgr_info (finfo=0x7ffcd9090460,
functionId=18230952) at fmgr.c:129
#4  OidFunctionCall1Coll (functionId=functionId@entry=1,
collation=collation@entry=0, arg1=arg1@entry=75471) at fmgr.c:1325
#5  0x0000000000532054 in ProcedureCreate (procedureName=<optimized
out>, procNamespace=procNamespace@entry=2200, replace=<optimized out>,
    returnsSet=returnsSet@entry=0 '\000',
returnType=returnType@entry=2950, proowner=10,
languageObjectId=languageObjectId@entry=13,
    languageValidator=languageValidator@entry=1,
prosrc=prosrc@entry=0x1139fb0 "uuid_nil", probin=probin@entry=0x1139f80
"$libdir/uuid-ossp", isAgg=isAgg@entry=0 '\000',
    isWindowFunc=isWindowFunc@entry=0 '\000',
security_definer=security_definer@entry=0 '\000',
isLeakProof=isLeakProof@entry=0 '\000', isStrict=isStrict@entry=1 '\001',
    volatility=volatility@entry=105 'i', parallel=parallel@entry=115
's', parameterTypes=parameterTypes@entry=0x1162e90,
allParameterTypes=allParameterTypes@entry=0,
    parameterModes=parameterModes@entry=0,
parameterNames=parameterNames@entry=0,
parameterDefaults=parameterDefaults@entry=0x0, trftypes=trftypes@entry=0,
    proconfig=proconfig@entry=0, procost=procost@entry=1,
prorows=prorows@entry=0) at pg_proc.c:714
#6  0x00000000005a3a2e in CreateFunction (pstate=pstate@entry=0x1133990,
stmt=stmt@entry=0x113a250) at functioncmds.c:1083
#7  0x0000000000720967 in ProcessUtilitySlow
(pstate=pstate@entry=0x1133990, pstmt=pstmt@entry=0x1149698,
    queryString=queryString@entry=0x113fb38 "/*
contrib/uuid-ossp/uuid-ossp--1.1.sql */\n\n-- complain if script is
sourced in psql, rather than via CREATE EXTENSION\n\n\nCREATE FUNCTION
uuid_nil()\nRETURNS uuid\nAS '$libdir/uuid-ossp', 'uuid_nil'\nIMMU"...,
context=context@entry=PROCESS_UTILITY_QUERY, params=params@entry=0x0,
    queryEnv=queryEnv@entry=0x0, completionTag=completionTag@entry=0x0,
dest=0xca42a0 <donothingDR>) at utility.c:1433
#8  0x000000000071fa6f in standard_ProcessUtility (pstmt=0x1149698,
    queryString=0x113fb38 "/* contrib/uuid-ossp/uuid-ossp--1.1.sql
*/\n\n-- complain if script is sourced in psql, rather than via CREATE
EXTENSION\n\n\nCREATE FUNCTION uuid_nil()\nRETURNS uuid\nAS
'$libdir/uuid-ossp', 'uuid_nil'\nIMMU"...,
context=PROCESS_UTILITY_QUERY, params=0x0, queryEnv=0x0, dest=0xca42a0
<donothingDR>,
    completionTag=0x0) at utility.c:931
#9  0x000000000059a6ac in execute_sql_string (filename=0x112bc18
"/usr/pgsql-10/share/extension/uuid-ossp--1.1.sql",
    sql=0x113fb38 "/* contrib/uuid-ossp/uuid-ossp--1.1.sql */\n\n--
complain if script is sourced in psql, rather than via CREATE
EXTENSION\n\n\nCREATE FUNCTION uuid_nil()\nRETURNS uuid\nAS
'$libdir/uuid-ossp', 'uuid_nil'\nIMMU"...) at extension.c:763
#10 execute_extension_script (extensionOid=extensionOid@entry=75470,
control=control@entry=0x112c310, from_version=from_version@entry=0x0,
    version=version@entry=0x1132b78 "1.1",
requiredSchemas=requiredSchemas@entry=0x0,
schemaName=schemaName@entry=0x112c2f8 "public", schemaOid=<optimized out>)
    at extension.c:924
#11 0x000000000059b135 in CreateExtensionInternal
(extensionName=0x10fa100 "uuid-ossp", schemaName=0x112c2f8 "public",
schemaName@entry=0x0, versionName=0x1132b78 "1.1",
    versionName@entry=0x0, oldVersionName=oldVersionName@entry=0x0,
cascade=<optimized out>, parents=parents@entry=0x0,
is_create=is_create@entry=1 '\001')
    at extension.c:1536
#12 0x000000000059b647 in CreateExtension
(pstate=pstate@entry=0x1149428, stmt=stmt@entry=0x10fa120) at
extension.c:1725
#13 0x0000000000720cdf in ProcessUtilitySlow
(pstate=pstate@entry=0x1149428, pstmt=pstmt@entry=0x10fa440,
    queryString=queryString@entry=0x10f9738 "create extension
\"uuid-ossp\" ;", context=context@entry=PROCESS_UTILITY_TOPLEVEL,
params=params@entry=0x0,
    queryEnv=queryEnv@entry=0x0,
completionTag=completionTag@entry=0x7ffcd9091930 "", dest=0x10fa520) at
utility.c:1352
#14 0x000000000071fa6f in standard_ProcessUtility (pstmt=0x10fa440,
queryString=0x10f9738 "create extension \"uuid-ossp\" ;",
context=PROCESS_UTILITY_TOPLEVEL,
    params=0x0, queryEnv=0x0, dest=0x10fa520,
completionTag=0x7ffcd9091930 "") at utility.c:931
#15 0x000000000071d368 in PortalRunUtility (portal=0x114a4c8,
pstmt=0x10fa440, isTopLevel=<optimized out>, setHoldSnapshot=<optimized
out>, dest=0x10fa520,
    completionTag=0x7ffcd9091930 "") at pquery.c:1178
#16 0x000000000071dda7 in PortalRunMulti (portal=portal@entry=0x114a4c8,
isTopLevel=isTopLevel@entry=1 '\001',
setHoldSnapshot=setHoldSnapshot@entry=0 '\000',
---Type <return> to continue, or q <return> to quit---
    dest=dest@entry=0x10fa520, altdest=altdest@entry=0x10fa520,
completionTag=completionTag@entry=0x7ffcd9091930 "") at pquery.c:1331
#17 0x000000000071e995 in PortalRun (portal=<optimized out>,
count=9223372036854775807, isTopLevel=<optimized out>,
run_once=<optimized out>, dest=0x10fa520,
    altdest=0x10fa520, completionTag=0x7ffcd9091930 "") at pquery.c:799
#18 0x000000000071aa13 in exec_simple_query (query_string=<optimized
out>) at postgres.c:1122
#19 0x000000000071bd0c in PostgresMain (argc=<optimized out>,
argv=<optimized out>, dbname=<optimized out>, username=<optimized out>)
at postgres.c:4117
#20 0x000000000047b246 in BackendRun (port=0x1098a20) at postmaster.c:4405
#21 BackendStartup (port=0x1098a20) at postmaster.c:4077
#22 ServerLoop () at postmaster.c:1755
#23 0x00000000006b25ef in PostmasterMain (argc=argc@entry=3,
argv=argv@entry=0x1070bc0) at postmaster.c:1363
#24 0x000000000047c06f in main (argc=3, argv=0x1070bc0) at main.c:228

Thanks,
Soni

On Tue, 2019-04-23 at 09:15 +0700, Soni wrote:

I install the contrib module from the postgres repo using yum
install.
creating extension run as postgres superuser.

Thanks,
Soni

1) Is there a uuid-ossp.control file sitting in the $SHAREDIR/extension
path?

2) Does its name exist in pg_available_extensions?

3) Is there a uuid-ossp.so in the lib path?

My 2 cents.

Cheers
Rob

Yes for that three questions.

-bash-4.2$ ls /usr/pgsql-10/share/extension/uuid-ossp.control
/usr/pgsql-10/share/extension/uuid-ossp.control

select * from pg_available_extensions where name = 'uuid-ossp';
   name    | default_version | installed_version |                    
comment
-----------+-----------------+-------------------+-------------------------------------------------
 uuid-ossp | 1.1             |                   | generate universally
unique identifiers (UUIDs)
(1 row)

-bash-4.2$ ls /usr/pgsql-10/lib/uuid-ossp.so
/usr/pgsql-10/lib/uuid-ossp.so

Thanks,
Soni

Soni <diptatapa@gmail.com> writes:

Here's the backtrace. Please let me know if it helps.

#4  OidFunctionCall1Coll (functionId=functionId@entry=1,
collation=collation@entry=0, arg1=arg1@entry=75471) at fmgr.c:1325

hm, there's "function 1" ...

#5  0x0000000000532054 in ProcedureCreate (procedureName=<optimized
out>, procNamespace=procNamespace@entry=2200, replace=<optimized out>,
    returnsSet=returnsSet@entry=0 '\000',
returnType=returnType@entry=2950, proowner=10,
languageObjectId=languageObjectId@entry=13,
    languageValidator=languageValidator@entry=1,

... and that's where it's coming from. Seems like you have corrupt
data in pg_language. Might be entertaining to see what
"select * from pg_language" gives.

regards, tom lane

Here it is:

select * from pg_language;
 lanname  | lanowner | lanispl | lanpltrusted | lanplcallfoid |
laninline | lanvalidator | lanacl
----------+----------+---------+--------------+---------------+-----------+--------------+--------
 internal |       10 | f       | f            |             0 |        
0 |         2246 |
 sql      |       10 | f       | t            |             0 |        
0 |         2248 |
 plpgsql  |       10 | t       | t            |         13793 |    
13794 |        13795 |
 c        |       10 | f       | f            |             0 |        
0 |            1 |
(4 rows)

Thanks,
Soni

Fix it, change the lanvalidator value of 1 to the value of fmgr_c_validator.
Thanks a lot Tom, that was fantastic. Not sure how the lanvalidator
value changed to 1.

Thanks,
Soni

Soni <diptatapa@gmail.com> writes:

Here it is:
select * from pg_language;
 lanname  | lanowner | lanispl | lanpltrusted | lanplcallfoid |
laninline | lanvalidator | lanacl
----------+----------+---------+--------------+---------------+-----------+--------------+--------
 internal |       10 | f       | f            |             0 |        
0 |         2246 |
 sql      |       10 | f       | t            |             0 |        
0 |         2248 |
 plpgsql  |       10 | t       | t            |         13793 |    
13794 |        13795 |
 c        |       10 | f       | f            |             0 |        
0 |            1 |
(4 rows)

Hm. That doesn't look like data corruption: that looks like
somebody actually did

update pg_language set lanvalidator = 1 where lanname = 'c';

or something equivalent to that. Needless to say, that was
not a good idea.

You said you reinstalled the postgres executables, but did you
re-initdb? Or even just re-create the current database?
I'm wondering if it's like that in every database of your cluster.

It'd be possible to fix this particular database by setting
lanvalidator back to its correct value (2247) but it'd be
wise to first inquire as to how it got like this.

regards, tom lane

I did not re-initdb, just use the old pgdata. I also did not recreate
current database.
Some of the database has value 1 for lanvalidator, some has 2247.

I'll check with the team how the lanvalidator got 1 for the value. I
will report back here.

Thanks,
Soni.