Thread
Commits
-
Fix planner error with pulling up subquery expressions into function RTEs.
- 4d5f651f1d65 15.0 landed
- fdd6a4d8d90a 13.5 landed
- fd059ac2e461 14.1 landed
-
Allow functions-in-FROM to be pulled up if they reduce to constants.
- 7266d0997dd2 13.0 cited
-
BUG #17227: segmentation fault with jsonb_to_recordset
The Post Office <noreply@postgresql.org> — 2021-10-13T09:16:08Z
The following bug has been logged on the website: Bug reference: 17227 Logged by: Bernd Dorn Email address: bernddorn@gmail.com PostgreSQL version: 14.0 Operating system: docker postgres:14 on osx Description: to reproduce : ``` docker run --name pg -p 5432:5432 --rm -e POSTGRES_PASSWORD=pw postgres:14 docker exec -ti pg psql --user postgres ``` run this query: ``` select * from ( select jsonb_path_query_array(module -> 'lectures', '$[*]') as lecture from unnest( array[$${ "lectures": [ { "id": "1" } ] }$$::jsonb]) as unnested_modules(module) ) as l, jsonb_to_recordset(l.lecture) as (id text) limit 1; ``` output in logs: ``` 2021-10-13 09:07:58.073 UTC [1] LOG: server process (PID 83) was terminated by signal 11: Segmentation fault 2021-10-13 09:07:58.073 UTC [1] DETAIL: Failed process was running: select * from ( select jsonb_path_query_array(module -> 'lectures', '$[*]') as lecture from unnest( array[$${ "lectures": [ { "id": "1" } ] }$$::jsonb]) as unnested_modules(module) ) as l, jsonb_to_recordset(l.lecture) as (id text) limit 1; 2021-10-13 09:07:58.073 UTC [1] LOG: terminating any other active server processes 2021-10-13 09:07:58.074 UTC [84] FATAL: the database system is in recovery mode 2021-10-13 09:07:58.076 UTC [1] LOG: all server processes terminated; reinitializing 2021-10-13 09:07:58.089 UTC [85] LOG: database system was interrupted; last known up at 2021-10-13 09:07:34 UTC 2021-10-13 09:07:58.180 UTC [85] LOG: database system was not properly shut down; automatic recovery in progress 2021-10-13 09:07:58.182 UTC [85] LOG: redo starts at 0/16FAB48 2021-10-13 09:07:58.182 UTC [85] LOG: invalid record length at 0/16FAB80: wanted 24, got 0 2021-10-13 09:07:58.182 UTC [85] LOG: redo done at 0/16FAB48 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s 2021-10-13 09:07:58.192 UTC [1] LOG: database system is ready to accept connections ``` -
Re: BUG #17227: segmentation fault with jsonb_to_recordset
Alvaro Herrera <alvherre@alvh.no-ip.org> — 2021-10-13T13:59:06Z
On 2021-Oct-13, PG Bug reporting form wrote: > ``` > select * > from ( > select jsonb_path_query_array(module -> 'lectures', '$[*]') as > lecture > from unnest( > array[$${ > "lectures": [ > { > "id": "1" > } > ] > }$$::jsonb]) as unnested_modules(module) > ) as l, > jsonb_to_recordset(l.lecture) as (id text) > limit 1; > ``` Can you provide some sample data that would reproduce the crash? -- Álvaro Herrera Valdivia, Chile — https://www.EnterpriseDB.com/ "It takes less than 2 seconds to get to 78% complete; that's a good sign. A few seconds later it's at 90%, but it seems to have stuck there. Did somebody make percentages logarithmic while I wasn't looking?" -
Re: BUG #17227: segmentation fault with jsonb_to_recordset
Tom Lane <tgl@sss.pgh.pa.us> — 2021-10-13T14:28:55Z
Alvaro Herrera <alvherre@alvh.no-ip.org> writes: > Can you provide some sample data that would reproduce the crash? Huh? It's a self-contained example. I'm seeing this back-trace on HEAD: #0 pg_detoast_datum (datum=0x40) at fmgr.c:1724 #1 0x00000000008a2c9a in jsonb_path_query_array_internal (fcinfo=0x19767d8, tz=<optimized out>) at jsonpath_exec.c:463 #2 0x00000000006ab46e in ExecInterpExpr (state=0x19766e8, econtext=0x1976560, isnull=<optimized out>) at execExprInterp.c:1260 #3 0x00000000006b8c04 in ExecEvalExpr (isNull=0x1991688, econtext=0x1976560, state=<optimized out>) at ../../../src/include/executor/executor.h:320 #4 ExecEvalFuncArgs (fcinfo=0x1991660, argList=0x198dd78, econtext=0x1976560) at execSRF.c:846 #5 0x00000000006b8f42 in ExecMakeTableFunctionResult (setexpr=0x1976650, econtext=0x1976560, argContext=0x1991540, expectedDesc=0x198de28, randomAccess=false) at execSRF.c:181 #6 0x00000000006cb5ef in FunctionNext (node=node@entry=0x1976348) at nodeFunctionscan.c:94 #7 0x00000000006b9b91 in ExecScanFetch ( recheckMtd=0x6cb2e0 <FunctionRecheck>, accessMtd=0x6cb2f0 <FunctionNext>, node=0x1976348) at execScan.c:133 #8 ExecScan (node=0x1976348, accessMtd=0x6cb2f0 <FunctionNext>, recheckMtd=0x6cb2e0 <FunctionRecheck>) at execScan.c:182 #9 0x00000000006e06d4 in ExecProcNode (node=0x1976348) at ../../../src/include/executor/executor.h:257 #10 ExecNestLoop (pstate=0x1975060) at nodeNestloop.c:160 regards, tom lane -
Re: BUG #17227: segmentation fault with jsonb_to_recordset
Tom Lane <tgl@sss.pgh.pa.us> — 2021-10-13T20:34:43Z
I wrote: > Huh? It's a self-contained example. I'm seeing this back-trace > on HEAD: Digging deeper, it seems jsonb_path_query_array_internal is being called with just two arguments: Breakpoint 1, jsonb_path_query_array_internal (fcinfo=0x2e6a4e8, tz=false) at jsonpath_exec.c:460 460 Jsonb *jb = PG_GETARG_JSONB_P(0); (gdb) p *fcinfo $1 = {flinfo = 0x2e6a490, context = 0x0, resultinfo = 0x0, fncollation = 0, isnull = false, nargs = 2, args = 0x2e6a508} It's expecting four arguments, and naturally goes off the deep end when the last two aren't there. Evidently the planner has failed to perform default-argument insertion on this particular function call. EXPLAIN VERBOSE shows the query plan as Nested Loop (cost=0.01..2.52 rows=100 width=64) Output: jsonb_path_query_array((unnested_modules.module -> 'lectures'::text), '$[*]'::jsonpath, '{}'::jsonb, false), jsonb_to_recordset.id -> Function Scan on pg_catalog.unnest unnested_modules (cost=0.00..0.01 rows=1 width=32) Output: unnested_modules.module Function Call: unnest('{"{\"lectures\": [{\"id\": \"1\"}]}"}'::jsonb[]) -> Function Scan on pg_catalog.jsonb_to_recordset (cost=0.01..1.01 rows=100 width=32) Output: jsonb_to_recordset.id Function Call: jsonb_to_recordset(jsonb_path_query_array((unnested_modules.module -> 'lectures'::text), '$[*]'::jsonpath)) so it looks like we have flattened the "as l" sub-select into the parent query and missed performing expression pre-processing on the expressions that were pulled up ... but only in the FunctionScan node. The call appearing in the output tlist has the default arguments in the right places. This works OK in v12, so somebody broke it between v12 and v13. More to follow ... regards, tom lane -
Re: BUG #17227: segmentation fault with jsonb_to_recordset
Tom Lane <tgl@sss.pgh.pa.us> — 2021-10-13T20:54:52Z
I wrote: > This works OK in v12, so somebody broke it between v12 and v13. Looks like the somebody was me. git bisect pins the blame on commit 7266d0997dd2a0632da38a594c78e25ff21df67e Author: Tom Lane <tgl@sss.pgh.pa.us> Date: Thu Aug 1 18:50:22 2019 -0400 Allow functions-in-FROM to be pulled up if they reduce to constants. A relevant-looking part of the commit message is To do this, we need to rearrange when eval_const_expressions() happens for expressions in function RTEs. I moved it to inline_set_returning_functions(), which already has to iterate over every function RTE, and in consequence renamed that function to preprocess_function_rtes(). Apparently this idea failed to account for subexpressions pulled up during later processing. Back to the drawing board. regards, tom lane -
Re: BUG #17227: segmentation fault with jsonb_to_recordset
Tom Lane <tgl@sss.pgh.pa.us> — 2021-10-13T22:58:10Z
I wrote: > Apparently this idea failed to account for subexpressions pulled up > during later processing. Back to the drawing board. After further study of 7266d0997, it seems we could fix this by the expedient of repeating eval_const_expressions on a function RTE whenever it contains LATERAL references. The code already understood that lateral join aliases were trouble, but it didn't account for the case of subexpressions inserted by subquery pullup (which'd have to have been lateral refs originally). The whole thing makes me itch a little bit, because this logic is assuming that eval_const_expressions is idempotent, something we can't test very well and (AFAIR) are not assuming anywhere else. If somebody made some sub-case not idempotent, we'd not notice until that case got used in a lateral function RTE. That could be a long time, as evidenced by the fact that this bug went undetected for a year since v13 release. However, we had that assumption in the code 7266d0997 replaced too, so this isn't adding any real new risk. I looked briefly at whether the planner's preprocessing steps could be re-ordered to eliminate the need for sometimes reprocessing function RTEs. It looks like it'd be a mess though, a conclusion I think I also reached before committing 7266d0997. Anyway, unless somebody has a better idea, I'll flesh out the attached with a test case and push it. regards, tom lane
-
Re: BUG #17227: segmentation fault with jsonb_to_recordset
Tom Lane <tgl@sss.pgh.pa.us> — 2021-10-14T15:29:33Z
I wrote: > The whole thing makes me itch a little bit, because this logic is > assuming that eval_const_expressions is idempotent, something > we can't test very well and (AFAIR) are not assuming anywhere else. > If somebody made some sub-case not idempotent, we'd not notice until > that case got used in a lateral function RTE. It occurred to me that we could test for problems with double execution of eval_const_expressions by making planner.c deliberately call it twice in all cases. A quick hack later, I can say that "make check-world" doesn't reveal any such problem. While that's hardly conclusive, it's pretty strong evidence, since the code coverage report shows eval_const_expressions as well covered (and the lines not reached are mostly returning simplified Const nodes, so hardly likely to be a problem here). We could make a persistent check for that by enclosing the extra calls in something like "#ifdef DOUBLE_EVAL_CONST_EXPRESSIONS" and setting up some buildfarm member to define that. But since (AFAIR) we've never actually had such a bug, it seems unlikely to be worth the trouble. I'll go ahead with the patch as presented. regards, tom lane