Version 10.1, Community version from PGDG repo
OS RHEL 7.3
I may have discovered a situation in 10.1 where EXECUTEing a PREPARED
statement acting on JSON data in partitioned tables hangs in an
infinite loop for a particular set of data. Unfortunately, the data is
proprietary, so I did the best I could below to describe what happened.
1) Partitioning is done with an (I hope) IMMUTABLE FUNC
2) Each partition has a partial index on IP address
3) The query looks for logins within a certain small time frame
from the same IP
I compiled a debug version and took 3 backtraces. When I first discovered
this, I allowed it to sit for 10-15 minutes before interrupting it.
Similar queries for different addresses return within seconds.
------------ Setup --------------
CREATE FUNCTION sesstime(tin JSONB)
RETURNS DATE
AS $$
SELECT (substring(tin->>'timestamp' from 1 for 8))::DATE;
$$ LANGUAGE SQL IMMUTABLE;
DROP TABLE sessparts;
CREATE TABLE sessparts
(
session JSONB
) PARTITION BY RANGE (sesstime(session));
CREATE TABLE sessparts_20171116
PARTITION OF sessparts
FOR VALUES FROM ('2017-11-16') TO ('2017-11-17');
CREATE TABLE sessparts_20171117
PARTITION OF sessparts
FOR VALUES FROM ('2017-11-17') TO ('2017-11-18');
--------------------------------------------
.....OTHER PARTITIONS ELIDED FOR BREVITY.....
--------------------------------------------
CREATE INDEX ON sessparts_20171116 (CAST(session->>'requestIP' AS INET))
WHERE session->>'requestIP' != ''
AND session->>'requestIP' != '0';
CREATE INDEX ON sessparts_20171117 (CAST(session->>'requestIP' AS INET))
WHERE session->>'requestIP' != ''
AND session->>'requestIP' != '0';
--------------------------------------------
.....OTHER PARTITIONS ELIDED FOR BREVITY.....
--------------------------------------------
PREPARE fanalq1(INET, TIMESTAMPTZ, INTERVAL) AS
SELECT inetad, aid, count(aid), stddev(td)
FROM (
SELECT $1, aid,
lid,
tstmp,
EXTRACT(EPOCH FROM (tstmp - lag(tstmp) OVER (ORDER BY tstmp)))
FROM (
SELECT session->>'authID' AUTHID,
session->>'loginID' LOGINID,
to_timestamp(session->>'timestamp', 'YYYYMMDDHH24MISS') tt
FROM sessparts
WHERE sesstime(session) >= ($2 - $3)::DATE
AND sesstime(session) <= $2::DATE
AND to_timestamp(session->>'timestamp', 'YYYYMMDDHH24MISS')
<@ tstzrange($2 - $3, $2)
AND session->>'requestIP' != ''
AND session->>'requestIP' != '0'
AND (session->>'requestIP')::INET = $1
AND session->>'isAuthenticationSuccessful' = 'false'
) attempts(aid, lid, tstmp)
) tdiffs(inetad, aid, lid, ts, td)
GROUP BY aid, 1;
------------ Query --------------
sessions=# explain EXECUTE fanalq1('206.108.41.102', '2017-11-17 16:23:31-05', '60 seconds');
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
GroupAggregate (cost=1175004.52..1175004.72 rows=8 width=80)
Group Key: tdiffs.aid, tdiffs.inetad
-> Sort (cost=1175004.52..1175004.54 rows=8 width=72)
Sort Key: tdiffs.aid, tdiffs.inetad
-> Subquery Scan on tdiffs (cost=1175004.00..1175004.40 rows=8 width=72)
-> WindowAgg (cost=1175004.00..1175004.32 rows=8 width=112)
-> Sort (cost=1175004.00..1175004.02 rows=8 width=1400)
Sort Key: (to_timestamp((sessparts_20171110.session ->> 'timestamp'::text), 'YYYYMMDDHH24MISS'::text))
-> Result (cost=74.23..1175003.88 rows=8 width=1400)
-> Append (cost=74.23..1175003.76 rows=8 width=1392)
-> Bitmap Heap Scan on sessparts_20171110 (cost=74.23..16077.23 rows=1 width=1380)
Recheck Cond: ((((session ->> 'requestIP'::text))::inet = '206.108.41.102'::inet) AND ((session ->> 'requestIP'::text) <> ''::text) AND ((session ->> 'requestIP'::text) <> '0'::text))
Filter: (((session ->> 'isAuthenticationSuccessful'::text) = 'false'::text) AND (to_timestamp((session ->> 'timestamp'::text), 'YYYYMMDDHH24MISS'::text) <@ tstzrange(('2017-11-17 16:23:31-05'::timestamp with time zone - '00:01:00'::interval), '2017-11-17 16:23:31-05'::timestamp with time zone)) AND (sesstime(session) <= ('2017-11-17 16:23:31-05'::timestamp with time zone)::date) AND (sesstime(session) >= (('2017-11-17 16:23:31-05'::timestamp with time zone - '00:01:00'::interval))::date))
-> Bitmap Index Scan on sessparts_20171110_inet_idx (cost=0.00..74.23 rows=3974 width=0)
Index Cond: (((session ->> 'requestIP'::text))::inet = '206.108.41.102'::inet)
-> Bitmap Heap Scan on sessparts_20171111 (cost=261.04..56514.03 rows=1 width=1420)
Recheck Cond: ((((session ->> 'requestIP'::text))::inet = '206.108.41.102'::inet) AND ((session ->> 'requestIP'::text) <> ''::text) AND ((session ->> 'requestIP'::text) <> '0'::text))
Filter: (((session ->> 'isAuthenticationSuccessful'::text) = 'false'::text) AND (to_timestamp((session ->> 'timestamp'::text), 'YYYYMMDDHH24MISS'::text) <@ tstzrange(('2017-11-17 16:23:31-05'::timestamp with time zone - '00:01:00'::interval), '2017-11-17 16:23:31-05'::timestamp with time zone)) AND (sesstime(session) <= ('2017-11-17 16:23:31-05'::timestamp with time zone)::date) AND (sesstime(session) >= (('2017-11-17 16:23:31-05'::timestamp with time zone - '00:01:00'::interval))::date))
-> Bitmap Index Scan on sessparts_20171111_inet_idx (cost=0.00..261.04 rows=13948 width=0)
Index Cond: (((session ->> 'requestIP'::text))::inet = '206.108.41.102'::inet)
-> Bitmap Heap Scan on sessparts_20171112 (cost=274.18..59053.83 rows=1 width=1342)
Recheck Cond: ((((session ->> 'requestIP'::text))::inet = '206.108.41.102'::inet) AND ((session ->> 'requestIP'::text) <> ''::text) AND ((session ->> 'requestIP'::text) <> '0'::text))
Filter: (((session ->> 'isAuthenticationSuccessful'::text) = 'false'::text) AND (to_timestamp((session ->> 'timestamp'::text), 'YYYYMMDDHH24MISS'::text) <@ tstzrange(('2017-11-17 16:23:31-05'::timestamp with time zone - '00:01:00'::interval), '2017-11-17 16:23:31-05'::timestamp with time zone)) AND (sesstime(session) <= ('2017-11-17 16:23:31-05'::timestamp with time zone)::date) AND (sesstime(session) >= (('2017-11-17 16:23:31-05'::timestamp with time zone - '00:01:00'::interval))::date))
-> Bitmap Index Scan on sessparts_20171112_inet_idx (cost=0.00..274.18 rows=14633 width=0)
Index Cond: (((session ->> 'requestIP'::text))::inet = '206.108.41.102'::inet)
-> Bitmap Heap Scan on sessparts_20171113 (cost=981.22..214235.52 rows=1 width=1395)
Recheck Cond: ((((session ->> 'requestIP'::text))::inet = '206.108.41.102'::inet) AND ((session ->> 'requestIP'::text) <> ''::text) AND ((session ->> 'requestIP'::text) <> '0'::text))
Filter: (((session ->> 'isAuthenticationSuccessful'::text) = 'false'::text) AND (to_timestamp((session ->> 'timestamp'::text), 'YYYYMMDDHH24MISS'::text) <@ tstzrange(('2017-11-17 16:23:31-05'::timestamp with time zone - '00:01:00'::interval), '2017-11-17 16:23:31-05'::timestamp with time zone)) AND (sesstime(session) <= ('2017-11-17 16:23:31-05'::timestamp with time zone)::date) AND (sesstime(session) >= (('2017-11-17 16:23:31-05'::timestamp with time zone - '00:01:00'::interval))::date))
-> Bitmap Index Scan on sessparts_20171113_inet_idx (cost=0.00..981.21 rows=52904 width=0)
Index Cond: (((session ->> 'requestIP'::text))::inet = '206.108.41.102'::inet)
-> Bitmap Heap Scan on sessparts_20171114 (cost=989.38..216526.98 rows=1 width=1397)
Recheck Cond: ((((session ->> 'requestIP'::text))::inet = '206.108.41.102'::inet) AND ((session ->> 'requestIP'::text) <> ''::text) AND ((session ->> 'requestIP'::text) <> '0'::text))
Filter: (((session ->> 'isAuthenticationSuccessful'::text) = 'false'::text) AND (to_timestamp((session ->> 'timestamp'::text), 'YYYYMMDDHH24MISS'::text) <@ tstzrange(('2017-11-17 16:23:31-05'::timestamp with time zone - '00:01:00'::interval), '2017-11-17 16:23:31-05'::timestamp with time zone)) AND (sesstime(session) <= ('2017-11-17 16:23:31-05'::timestamp with time zone)::date) AND (sesstime(session) >= (('2017-11-17 16:23:31-05'::timestamp with time zone - '00:01:00'::interval))::date))
-> Bitmap Index Scan on sessparts_20171114_inet_idx (cost=0.00..989.38 rows=53459 width=0)
Index Cond: (((session ->> 'requestIP'::text))::inet = '206.108.41.102'::inet)
-> Bitmap Heap Scan on sessparts_20171115 (cost=975.53..213392.42 rows=1 width=1401)
Recheck Cond: ((((session ->> 'requestIP'::text))::inet = '206.108.41.102'::inet) AND ((session ->> 'requestIP'::text) <> ''::text) AND ((session ->> 'requestIP'::text) <> '0'::text))
Filter: (((session ->> 'isAuthenticationSuccessful'::text) = 'false'::text) AND (to_timestamp((session ->> 'timestamp'::text), 'YYYYMMDDHH24MISS'::text) <@ tstzrange(('2017-11-17 16:23:31-05'::timestamp with time zone - '00:01:00'::interval), '2017-11-17 16:23:31-05'::timestamp with time zone)) AND (sesstime(session) <= ('2017-11-17 16:23:31-05'::timestamp with time zone)::date) AND (sesstime(session) >= (('2017-11-17 16:23:31-05'::timestamp with time zone - '00:01:00'::interval))::date))
-> Bitmap Index Scan on sessparts_20171115_inet_idx (cost=0.00..975.53 rows=52679 width=0)
Index Cond: (((session ->> 'requestIP'::text))::inet = '206.108.41.102'::inet)
-> Bitmap Heap Scan on sessparts_20171116 (cost=1042.06..227732.56 rows=1 width=1400)
Recheck Cond: ((((session ->> 'requestIP'::text))::inet = '206.108.41.102'::inet) AND ((session ->> 'requestIP'::text) <> ''::text) AND ((session ->> 'requestIP'::text) <> '0'::text))
Filter: (((session ->> 'isAuthenticationSuccessful'::text) = 'false'::text) AND (to_timestamp((session ->> 'timestamp'::text), 'YYYYMMDDHH24MISS'::text) <@ tstzrange(('2017-11-17 16:23:31-05'::timestamp with time zone - '00:01:00'::interval), '2017-11-17 16:23:31-05'::timestamp with time zone)) AND (sesstime(session) <= ('2017-11-17 16:23:31-05'::timestamp with time zone)::date) AND (sesstime(session) >= (('2017-11-17 16:23:31-05'::timestamp with time zone - '00:01:00'::interval))::date))
-> Bitmap Index Scan on sessparts_20171116_inet_idx (cost=0.00..1042.06 rows=56217 width=0)
Index Cond: (((session ->> 'requestIP'::text))::inet = '206.108.41.102'::inet)
-> Bitmap Heap Scan on sessparts_20171117 (cost=785.91..171471.19 rows=1 width=1401)
Recheck Cond: ((((session ->> 'requestIP'::text))::inet = '206.108.41.102'::inet) AND ((session ->> 'requestIP'::text) <> ''::text) AND ((session ->> 'requestIP'::text) <> '0'::text))
Filter: (((session ->> 'isAuthenticationSuccessful'::text) = 'false'::text) AND (to_timestamp((session ->> 'timestamp'::text), 'YYYYMMDDHH24MISS'::text) <@ tstzrange(('2017-11-17 16:23:31-05'::timestamp with time zone - '00:01:00'::interval), '2017-11-17 16:23:31-05'::timestamp with time zone)) AND (sesstime(session) <= ('2017-11-17 16:23:31-05'::timestamp with time zone)::date) AND (sesstime(session) >= (('2017-11-17 16:23:31-05'::timestamp with time zone - '00:01:00'::interval))::date))
-> Bitmap Index Scan on sessparts_20171117_inet_idx (cost=0.00..785.91 rows=42330 width=0)
Index Cond: (((session ->> 'requestIP'::text))::inet = '206.108.41.102'::inet)
(50 rows)
--------- Backtrace #1 ----------
(gdb) bt
#0 0x00007fc326cae480 in __read_nocancel () from /lib64/libpthread.so.0
#1 0x00000000006ec65e in read (__nbytes=8192, __buf=0x7fbf1a41f800, __fd=<optimized out>) at /usr/include/bits/unistd.h:44
#2 FileRead (file=<optimized out>, buffer=buffer@entry=0x7fbf1a41f800 "#", amount=amount@entry=8192, wait_event_info=wait_event_info@entry=167772173) at fd.c:1665
#3 0x000000000070f036 in mdread (reln=<optimized out>, forknum=<optimized out>, blocknum=175416, buffer=0x7fbf1a41f800 "#") at md.c:757
#4 0x00000000006e8af8 in ReadBuffer_common (smgr=0x15408f8, relpersistence=<optimized out>, forkNum=forkNum@entry=MAIN_FORKNUM, blockNum=blockNum@entry=175416,
mode=RBM_NORMAL, strategy=0x0, hit=hit@entry=0x7ffe3a6e14e7 "") at bufmgr.c:890
#5 0x00000000006e9600 in ReadBufferExtended (reln=0x7fc32709d880, forkNum=forkNum@entry=MAIN_FORKNUM, blockNum=175416, mode=mode@entry=RBM_NORMAL,
strategy=strategy@entry=0x0) at bufmgr.c:664
#6 0x00000000006e971b in ReadBuffer (blockNum=<optimized out>, reln=<optimized out>) at bufmgr.c:596
#7 ReleaseAndReadBuffer (buffer=<optimized out>, relation=<optimized out>, blockNum=blockNum@entry=175416) at bufmgr.c:1545
#8 0x00000000005fdd94 in bitgetpage (tbmres=0x16c6e0c, scan=0x1683bc8) at nodeBitmapHeapscan.c:364
#9 BitmapHeapNext (node=node@entry=0x1676b08) at nodeBitmapHeapscan.c:230
#10 0x00000000005f3254 in ExecScanFetch (recheckMtd=0x5fdb30 <BitmapHeapRecheck>, accessMtd=0x5fdbc0 <BitmapHeapNext>, node=0x1676b08) at execScan.c:97
#11 ExecScan (node=0x1676b08, accessMtd=0x5fdbc0 <BitmapHeapNext>, recheckMtd=0x5fdb30 <BitmapHeapRecheck>) at execScan.c:164
#12 0x00000000005f8c02 in ExecProcNode (node=0x1676b08) at ../../../src/include/executor/executor.h:250
#13 ExecAppend (pstate=0x1672800) at nodeAppend.c:222
#14 0x000000000060ce79 in ExecProcNode (node=0x1672800) at ../../../src/include/executor/executor.h:250
#15 ExecResult (pstate=0x1672590) at nodeResult.c:115
#16 0x000000000060e5c6 in ExecProcNode (node=0x1672590) at ../../../src/include/executor/executor.h:250
#17 ExecSort (pstate=0x1672320) at nodeSort.c:106
#18 0x000000000061264c in ExecProcNode (node=0x1672320) at ../../../src/include/executor/executor.h:250
#19 begin_partition (winstate=winstate@entry=0x1671b90) at nodeWindowAgg.c:1082
#20 0x0000000000614f64 in ExecWindowAgg (pstate=0x1671b90) at nodeWindowAgg.c:1671
#21 0x00000000005f3254 in ExecScanFetch (recheckMtd=0x611290 <SubqueryRecheck>, accessMtd=0x6112b0 <SubqueryNext>, node=0x1671870) at execScan.c:97
#22 ExecScan (node=0x1671870, accessMtd=0x6112b0 <SubqueryNext>, recheckMtd=0x611290 <SubqueryRecheck>) at execScan.c:164
#23 0x000000000060e5c6 in ExecProcNode (node=0x1671870) at ../../../src/include/executor/executor.h:250
#24 ExecSort (pstate=0x1671600) at nodeSort.c:106
#25 0x00000000005f8f49 in ExecProcNode (node=0x1671600) at ../../../src/include/executor/executor.h:250
#26 fetch_input_tuple (aggstate=aggstate@entry=0x1670f58) at nodeAgg.c:695
#27 0x00000000005fb0c7 in agg_retrieve_direct (aggstate=0x1670f58) at nodeAgg.c:2336
#28 ExecAgg (pstate=0x1670f58) at nodeAgg.c:2147
#29 0x00000000005ed7e2 in ExecProcNode (node=0x1670f58) at ../../../src/include/executor/executor.h:250
#30 ExecutePlan (execute_once=<optimized out>, dest=0x15f5f10, direction=<optimized out>, numberTuples=0, sendTuples=1 '\001', operation=CMD_SELECT,
use_parallel_mode=<optimized out>, planstate=0x1670f58, estate=0x1670d48) at execMain.c:1722
#31 standard_ExecutorRun (queryDesc=0x14d9b08, direction=<optimized out>, count=0, execute_once=<optimized out>) at execMain.c:363
#32 0x00000000007167db in PortalRunSelect (portal=portal@entry=0x152cdc8, forward=forward@entry=1 '\001', count=0, count@entry=9223372036854775807,
dest=dest@entry=0x15f5f10) at pquery.c:932
#33 0x0000000000717b7f in PortalRun (portal=portal@entry=0x152cdc8, count=count@entry=9223372036854775807, isTopLevel=isTopLevel@entry=0 '\000',
run_once=run_once@entry=1 '\001', dest=dest@entry=0x15f5f10, altdest=altdest@entry=0x15f5f10, completionTag=completionTag@entry=0x7ffe3a6e1c40 "") at pquery.c:773
#34 0x00000000005abd3e in ExecuteQuery (stmt=<optimized out>, intoClause=0x0, queryString=<optimized out>, params=<optimized out>, dest=0x15f5f10,
completionTag=0x7ffe3a6e1c40 "") at prepare.c:304
#35 0x0000000000718cfa in standard_ProcessUtility (pstmt=0x1532b28,
queryString=0x1531bf8 "EXECUTE fanalq1('206.108.41.102', '2017-11-17 16:23:31-05', '60 seconds');", context=PROCESS_UTILITY_TOPLEVEL, params=0x0, queryEnv=0x0,
dest=0x15f5f10, completionTag=0x7ffe3a6e1c40 "") at utility.c:576
#36 0x0000000000716458 in PortalRunUtility (portal=0x152ccb8, pstmt=0x1532b28, isTopLevel=<optimized out>, setHoldSnapshot=<optimized out>, dest=0x15f5f10,
completionTag=0x7ffe3a6e1c40 "") at pquery.c:1178
#37 0x0000000000717172 in FillPortalStore (portal=portal@entry=0x152ccb8, isTopLevel=isTopLevel@entry=1 '\001') at pquery.c:1038
#38 0x0000000000717bff in PortalRun (portal=portal@entry=0x152ccb8, count=count@entry=9223372036854775807, isTopLevel=isTopLevel@entry=1 '\001',
run_once=run_once@entry=1 '\001', dest=dest@entry=0x1532c08, altdest=altdest@entry=0x1532c08, completionTag=completionTag@entry=0x7ffe3a6e1e60 "") at pquery.c:768
#39 0x0000000000713b03 in exec_simple_query (query_string=0x1531bf8 "EXECUTE fanalq1('206.108.41.102', '2017-11-17 16:23:31-05', '60 seconds');") at postgres.c:1099
#40 0x0000000000714dfc in PostgresMain (argc=<optimized out>, argv=argv@entry=0x14dc860, dbname=0x14dc758 "sessions", username=<optimized out>) at postgres.c:4088
#41 0x0000000000479b4c in BackendRun (port=0x14d2d80) at postmaster.c:4357
#42 BackendStartup (port=0x14d2d80) at postmaster.c:4029
#43 ServerLoop () at postmaster.c:1753
#44 0x00000000006ac63f in PostmasterMain (argc=argc@entry=13, argv=argv@entry=0x14ac250) at postmaster.c:1361
#45 0x000000000047a97f in main (argc=13, argv=0x14ac250) at main.c:228
--------- Backtrace #2 ----------
(gdb) bt
#0 0x00007fc326cae480 in __read_nocancel () from /lib64/libpthread.so.0
#1 0x00000000006ec65e in read (__nbytes=8192, __buf=0x7fbf1c33b800, __fd=<optimized out>) at /usr/include/bits/unistd.h:44
#2 FileRead (file=<optimized out>, buffer=buffer@entry=0x7fbf1c33b800 "#", amount=amount@entry=8192, wait_event_info=wait_event_info@entry=167772173) at fd.c:1665
#3 0x000000000070f036 in mdread (reln=<optimized out>, forknum=<optimized out>, blocknum=272410, buffer=0x7fbf1c33b800 "#") at md.c:757
#4 0x00000000006e8af8 in ReadBuffer_common (smgr=0x15408f8, relpersistence=<optimized out>, forkNum=forkNum@entry=MAIN_FORKNUM, blockNum=blockNum@entry=272410,
mode=RBM_NORMAL, strategy=0x0, hit=hit@entry=0x7ffe3a6e14e7 "") at bufmgr.c:890
#5 0x00000000006e9600 in ReadBufferExtended (reln=0x7fc32709d880, forkNum=forkNum@entry=MAIN_FORKNUM, blockNum=272410, mode=mode@entry=RBM_NORMAL,
strategy=strategy@entry=0x0) at bufmgr.c:664
#6 0x00000000006e971b in ReadBuffer (blockNum=<optimized out>, reln=<optimized out>) at bufmgr.c:596
#7 ReleaseAndReadBuffer (buffer=<optimized out>, relation=<optimized out>, blockNum=blockNum@entry=272410) at bufmgr.c:1545
#8 0x00000000005fdd94 in bitgetpage (tbmres=0x16c6e0c, scan=0x1683bc8) at nodeBitmapHeapscan.c:364
#9 BitmapHeapNext (node=node@entry=0x1676b08) at nodeBitmapHeapscan.c:230
#10 0x00000000005f3254 in ExecScanFetch (recheckMtd=0x5fdb30 <BitmapHeapRecheck>, accessMtd=0x5fdbc0 <BitmapHeapNext>, node=0x1676b08) at execScan.c:97
#11 ExecScan (node=0x1676b08, accessMtd=0x5fdbc0 <BitmapHeapNext>, recheckMtd=0x5fdb30 <BitmapHeapRecheck>) at execScan.c:164
#12 0x00000000005f8c02 in ExecProcNode (node=0x1676b08) at ../../../src/include/executor/executor.h:250
#13 ExecAppend (pstate=0x1672800) at nodeAppend.c:222
#14 0x000000000060ce79 in ExecProcNode (node=0x1672800) at ../../../src/include/executor/executor.h:250
#15 ExecResult (pstate=0x1672590) at nodeResult.c:115
#16 0x000000000060e5c6 in ExecProcNode (node=0x1672590) at ../../../src/include/executor/executor.h:250
#17 ExecSort (pstate=0x1672320) at nodeSort.c:106
#18 0x000000000061264c in ExecProcNode (node=0x1672320) at ../../../src/include/executor/executor.h:250
#19 begin_partition (winstate=winstate@entry=0x1671b90) at nodeWindowAgg.c:1082
#20 0x0000000000614f64 in ExecWindowAgg (pstate=0x1671b90) at nodeWindowAgg.c:1671
#21 0x00000000005f3254 in ExecScanFetch (recheckMtd=0x611290 <SubqueryRecheck>, accessMtd=0x6112b0 <SubqueryNext>, node=0x1671870) at execScan.c:97
#22 ExecScan (node=0x1671870, accessMtd=0x6112b0 <SubqueryNext>, recheckMtd=0x611290 <SubqueryRecheck>) at execScan.c:164
#23 0x000000000060e5c6 in ExecProcNode (node=0x1671870) at ../../../src/include/executor/executor.h:250
#24 ExecSort (pstate=0x1671600) at nodeSort.c:106
#25 0x00000000005f8f49 in ExecProcNode (node=0x1671600) at ../../../src/include/executor/executor.h:250
#26 fetch_input_tuple (aggstate=aggstate@entry=0x1670f58) at nodeAgg.c:695
#27 0x00000000005fb0c7 in agg_retrieve_direct (aggstate=0x1670f58) at nodeAgg.c:2336
#28 ExecAgg (pstate=0x1670f58) at nodeAgg.c:2147
#29 0x00000000005ed7e2 in ExecProcNode (node=0x1670f58) at ../../../src/include/executor/executor.h:250
#30 ExecutePlan (execute_once=<optimized out>, dest=0x15f5f10, direction=<optimized out>, numberTuples=0, sendTuples=1 '\001', operation=CMD_SELECT,
use_parallel_mode=<optimized out>, planstate=0x1670f58, estate=0x1670d48) at execMain.c:1722
#31 standard_ExecutorRun (queryDesc=0x14d9b08, direction=<optimized out>, count=0, execute_once=<optimized out>) at execMain.c:363
#32 0x00000000007167db in PortalRunSelect (portal=portal@entry=0x152cdc8, forward=forward@entry=1 '\001', count=0, count@entry=9223372036854775807,
dest=dest@entry=0x15f5f10) at pquery.c:932
#33 0x0000000000717b7f in PortalRun (portal=portal@entry=0x152cdc8, count=count@entry=9223372036854775807, isTopLevel=isTopLevel@entry=0 '\000',
run_once=run_once@entry=1 '\001', dest=dest@entry=0x15f5f10, altdest=altdest@entry=0x15f5f10, completionTag=completionTag@entry=0x7ffe3a6e1c40 "") at pquery.c:773
#34 0x00000000005abd3e in ExecuteQuery (stmt=<optimized out>, intoClause=0x0, queryString=<optimized out>, params=<optimized out>, dest=0x15f5f10,
completionTag=0x7ffe3a6e1c40 "") at prepare.c:304
#35 0x0000000000718cfa in standard_ProcessUtility (pstmt=0x1532b28,
queryString=0x1531bf8 "EXECUTE fanalq1('206.108.41.102', '2017-11-17 16:23:31-05', '60 seconds');", context=PROCESS_UTILITY_TOPLEVEL, params=0x0, queryEnv=0x0,
dest=0x15f5f10, completionTag=0x7ffe3a6e1c40 "") at utility.c:576
#36 0x0000000000716458 in PortalRunUtility (portal=0x152ccb8, pstmt=0x1532b28, isTopLevel=<optimized out>, setHoldSnapshot=<optimized out>, dest=0x15f5f10,
completionTag=0x7ffe3a6e1c40 "") at pquery.c:1178
#37 0x0000000000717172 in FillPortalStore (portal=portal@entry=0x152ccb8, isTopLevel=isTopLevel@entry=1 '\001') at pquery.c:1038
#38 0x0000000000717bff in PortalRun (portal=portal@entry=0x152ccb8, count=count@entry=9223372036854775807, isTopLevel=isTopLevel@entry=1 '\001',
run_once=run_once@entry=1 '\001', dest=dest@entry=0x1532c08, altdest=altdest@entry=0x1532c08, completionTag=completionTag@entry=0x7ffe3a6e1e60 "") at pquery.c:768
#39 0x0000000000713b03 in exec_simple_query (query_string=0x1531bf8 "EXECUTE fanalq1('206.108.41.102', '2017-11-17 16:23:31-05', '60 seconds');") at postgres.c:1099
#40 0x0000000000714dfc in PostgresMain (argc=<optimized out>, argv=argv@entry=0x14dc860, dbname=0x14dc758 "sessions", username=<optimized out>) at postgres.c:4088
#41 0x0000000000479b4c in BackendRun (port=0x14d2d80) at postmaster.c:4357
#42 BackendStartup (port=0x14d2d80) at postmaster.c:4029
#43 ServerLoop () at postmaster.c:1753
#44 0x00000000006ac63f in PostmasterMain (argc=argc@entry=13, argv=argv@entry=0x14ac250) at postmaster.c:1361
#45 0x000000000047a97f in main (argc=13, argv=0x14ac250) at main.c:228
--------- Backtrace #3 ----------
(gdb) bt
#0 0x00007fc326cae480 in __read_nocancel () from /lib64/libpthread.so.0
#1 0x00000000006ec65e in read (__nbytes=8192, __buf=0x7fbf1cc33800, __fd=<optimized out>) at /usr/include/bits/unistd.h:44
#2 FileRead (file=<optimized out>, buffer=buffer@entry=0x7fbf1cc33800 "#", amount=amount@entry=8192, wait_event_info=wait_event_info@entry=167772173) at fd.c:1665
#3 0x000000000070f036 in mdread (reln=<optimized out>, forknum=<optimized out>, blocknum=303087, buffer=0x7fbf1cc33800 "#") at md.c:757
#4 0x00000000006e8af8 in ReadBuffer_common (smgr=0x15408f8, relpersistence=<optimized out>, forkNum=forkNum@entry=MAIN_FORKNUM, blockNum=blockNum@entry=303087,
mode=RBM_NORMAL, strategy=0x0, hit=hit@entry=0x7ffe3a6e14e7 "") at bufmgr.c:890
#5 0x00000000006e9600 in ReadBufferExtended (reln=0x7fc32709d880, forkNum=forkNum@entry=MAIN_FORKNUM, blockNum=303087, mode=mode@entry=RBM_NORMAL,
strategy=strategy@entry=0x0) at bufmgr.c:664
#6 0x00000000006e971b in ReadBuffer (blockNum=<optimized out>, reln=<optimized out>) at bufmgr.c:596
#7 ReleaseAndReadBuffer (buffer=<optimized out>, relation=<optimized out>, blockNum=blockNum@entry=303087) at bufmgr.c:1545
#8 0x00000000005fdd94 in bitgetpage (tbmres=0x16c6e0c, scan=0x1683bc8) at nodeBitmapHeapscan.c:364
#9 BitmapHeapNext (node=node@entry=0x1676b08) at nodeBitmapHeapscan.c:230
#10 0x00000000005f3254 in ExecScanFetch (recheckMtd=0x5fdb30 <BitmapHeapRecheck>, accessMtd=0x5fdbc0 <BitmapHeapNext>, node=0x1676b08) at execScan.c:97
#11 ExecScan (node=0x1676b08, accessMtd=0x5fdbc0 <BitmapHeapNext>, recheckMtd=0x5fdb30 <BitmapHeapRecheck>) at execScan.c:164
#12 0x00000000005f8c02 in ExecProcNode (node=0x1676b08) at ../../../src/include/executor/executor.h:250
#13 ExecAppend (pstate=0x1672800) at nodeAppend.c:222
#14 0x000000000060ce79 in ExecProcNode (node=0x1672800) at ../../../src/include/executor/executor.h:250
#15 ExecResult (pstate=0x1672590) at nodeResult.c:115
#16 0x000000000060e5c6 in ExecProcNode (node=0x1672590) at ../../../src/include/executor/executor.h:250
#17 ExecSort (pstate=0x1672320) at nodeSort.c:106
#18 0x000000000061264c in ExecProcNode (node=0x1672320) at ../../../src/include/executor/executor.h:250
#19 begin_partition (winstate=winstate@entry=0x1671b90) at nodeWindowAgg.c:1082
#20 0x0000000000614f64 in ExecWindowAgg (pstate=0x1671b90) at nodeWindowAgg.c:1671
#21 0x00000000005f3254 in ExecScanFetch (recheckMtd=0x611290 <SubqueryRecheck>, accessMtd=0x6112b0 <SubqueryNext>, node=0x1671870) at execScan.c:97
#22 ExecScan (node=0x1671870, accessMtd=0x6112b0 <SubqueryNext>, recheckMtd=0x611290 <SubqueryRecheck>) at execScan.c:164
#23 0x000000000060e5c6 in ExecProcNode (node=0x1671870) at ../../../src/include/executor/executor.h:250
#24 ExecSort (pstate=0x1671600) at nodeSort.c:106
#25 0x00000000005f8f49 in ExecProcNode (node=0x1671600) at ../../../src/include/executor/executor.h:250
#26 fetch_input_tuple (aggstate=aggstate@entry=0x1670f58) at nodeAgg.c:695
#27 0x00000000005fb0c7 in agg_retrieve_direct (aggstate=0x1670f58) at nodeAgg.c:2336
#28 ExecAgg (pstate=0x1670f58) at nodeAgg.c:2147
#29 0x00000000005ed7e2 in ExecProcNode (node=0x1670f58) at ../../../src/include/executor/executor.h:250
#30 ExecutePlan (execute_once=<optimized out>, dest=0x15f5f10, direction=<optimized out>, numberTuples=0, sendTuples=1 '\001', operation=CMD_SELECT,
use_parallel_mode=<optimized out>, planstate=0x1670f58, estate=0x1670d48) at execMain.c:1722
#31 standard_ExecutorRun (queryDesc=0x14d9b08, direction=<optimized out>, count=0, execute_once=<optimized out>) at execMain.c:363
#32 0x00000000007167db in PortalRunSelect (portal=portal@entry=0x152cdc8, forward=forward@entry=1 '\001', count=0, count@entry=9223372036854775807,
dest=dest@entry=0x15f5f10) at pquery.c:932
#33 0x0000000000717b7f in PortalRun (portal=portal@entry=0x152cdc8, count=count@entry=9223372036854775807, isTopLevel=isTopLevel@entry=0 '\000',
run_once=run_once@entry=1 '\001', dest=dest@entry=0x15f5f10, altdest=altdest@entry=0x15f5f10, completionTag=completionTag@entry=0x7ffe3a6e1c40 "") at pquery.c:773
#34 0x00000000005abd3e in ExecuteQuery (stmt=<optimized out>, intoClause=0x0, queryString=<optimized out>, params=<optimized out>, dest=0x15f5f10,
completionTag=0x7ffe3a6e1c40 "") at prepare.c:304
#35 0x0000000000718cfa in standard_ProcessUtility (pstmt=0x1532b28,
queryString=0x1531bf8 "EXECUTE fanalq1('206.108.41.102', '2017-11-17 16:23:31-05', '60 seconds');", context=PROCESS_UTILITY_TOPLEVEL, params=0x0, queryEnv=0x0,
dest=0x15f5f10, completionTag=0x7ffe3a6e1c40 "") at utility.c:576
#36 0x0000000000716458 in PortalRunUtility (portal=0x152ccb8, pstmt=0x1532b28, isTopLevel=<optimized out>, setHoldSnapshot=<optimized out>, dest=0x15f5f10,
completionTag=0x7ffe3a6e1c40 "") at pquery.c:1178
#37 0x0000000000717172 in FillPortalStore (portal=portal@entry=0x152ccb8, isTopLevel=isTopLevel@entry=1 '\001') at pquery.c:1038
#38 0x0000000000717bff in PortalRun (portal=portal@entry=0x152ccb8, count=count@entry=9223372036854775807, isTopLevel=isTopLevel@entry=1 '\001',
run_once=run_once@entry=1 '\001', dest=dest@entry=0x1532c08, altdest=altdest@entry=0x1532c08, completionTag=completionTag@entry=0x7ffe3a6e1e60 "") at pquery.c:768
#39 0x0000000000713b03 in exec_simple_query (query_string=0x1531bf8 "EXECUTE fanalq1('206.108.41.102', '2017-11-17 16:23:31-05', '60 seconds');") at postgres.c:1099
#40 0x0000000000714dfc in PostgresMain (argc=<optimized out>, argv=argv@entry=0x14dc860, dbname=0x14dc758 "sessions", username=<optimized out>) at postgres.c:4088
#41 0x0000000000479b4c in BackendRun (port=0x14d2d80) at postmaster.c:4357
#42 BackendStartup (port=0x14d2d80) at postmaster.c:4029
#43 ServerLoop () at postmaster.c:1753
#44 0x00000000006ac63f in PostmasterMain (argc=argc@entry=13, argv=argv@entry=0x14ac250) at postmaster.c:1361
#45 0x000000000047a97f in main (argc=13, argv=0x14ac250) at main.c:228
