Re: max_stack_depth problem though query is substantially smaller

From: "Bannert Matthias" <bannert(at)kof(dot)ethz(dot)ch>
To: Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>
Cc: Charles Clavadetscher <clavadetscher(at)swisspug(dot)org>, "pgsql-general(at)postgresql(dot)org" <pgsql-general(at)postgresql(dot)org>
Subject: Re: max_stack_depth problem though query is substantially smaller
Date: 2016-04-09 10:50:41
Message-ID: 8586FCA42D306C4DB0BD46EF9F1B58025AFA649C@MBX110.d.ethz.ch
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-general

I am not sure if I did it the right way, cause it's my first time stack tracing, but I did get some more information.
Here's what I did.

1. Switched to ubuntu server 14.04 /w postgres 9.3 server (in a Virtual Box VM)
2. setup postgres and made sure I was able to reproduce the same error.
3. followed the link to get gdb etc going.
4. started a psql session and determined the pid using SELECT pg_backend_pid();
5. attached the backend to gdb: sudo gdb -p 1521
6. in gdb:
(gdb) set pagination off
(gdb) set logging file debuglog.txt
(gdb) set logging on
break errfinish
cont
7. in psql: \i query.sql
query.sql contains a create TABLE statement and the 1.7 MB INSERT with the 40K pairs hstore.

8. in gdb: ctrl + c
bt
detach
quit

Finally that logfile hast almost 4 MB, so I am not posting it here.
Yet, here are some lines that might be helpful.... In case there is anything in particular I could look for, please let me know...

Breakpoint 1, errfinish (dummy=0) at /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/utils/error/elog.c:406
406 /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/utils/error/elog.c: No such file or directory.
#0 errfinish (dummy=0) at /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/utils/error/elog.c:406
#1 0x00007fe7fb809c67 in check_stack_depth () at /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/tcop/postgres.c:3115
#2 0x00007fe7fb6b9177 in transformExprRecurse (pstate=pstate(at)entry=0x7fe7fffdb340, expr=expr(at)entry=0x7fe7ff8fc8d0) at /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/parser/parse_expr.c:132
#3 0x00007fe7fb6ba314 in transformAExprOp (a=0x7fe7ff8fcb88, pstate=0x7fe7fffdb340) at /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/parser/parse_expr.c:907
#4 transformExprRecurse (pstate=pstate(at)entry=0x7fe7fffdb340, expr=expr(at)entry=0x7fe7ff8fcb88) at /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/parser/parse_expr.c:223
#5 0x00007fe7fb6ba314 in transformAExprOp (a=0x7fe7ff8fce58, pstate=0x7fe7fffdb340) at /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/parser/parse_expr.c:907

what follows are tons of similar lines, just at the end it seems to get more specific, i.e. mentioning the hstore:

#20133 0x00007fe7fb698d74 in transformInsertStmt (stmt=0x7fe7fffdb2a0, pstate=0x7fe7fffdb340) at /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/parser/analyze.c:701
#20134 transformStmt (pstate=pstate(at)entry=0x7fe7fffdb340, parseTree=0x7fe7fffdb2a0) at /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/parser/analyze.c:225
#20135 0x00007fe7fb699e43 in transformTopLevelStmt (pstate=pstate(at)entry=0x7fe7fffdb340, parseTree=<optimized out>, parseTree(at)entry=0x7fe7fffdb2a0) at /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/parser/analyze.c:207
#20136 0x00007fe7fb699ee9 in parse_analyze (parseTree=0x7fe7fffdb2a0, sourceText=0x7fe7fdf606b0 "INSERT INTO ts_updates(ts_key, ts_data, ts_frequency) VALUES ('some_id.sector_all.news_all_d',hstore('1900-01-01','-0.395131869823009')||hstore('1900-01-02','-0.395131869823009')||hstore('1"..., paramTypes=0x0, numParams=0) at /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/parser/analyze.c:100
#20137 0x00007fe7fb80ab8c in pg_analyze_and_rewrite (parsetree=parsetree(at)entry=0x7fe7fffdb2a0, query_string=query_string(at)entry=0x7fe7fdf606b0 "INSERT INTO ts_updates(ts_key, ts_data, ts_frequency) VALUES ('some_id.sector_all.news_all_d',hstore('1900-01-01','-0.395131869823009')||hstore('1900-01-02','-0.395131869823009')||hstore('1"..., paramTypes=paramTypes(at)entry=0x0, numParams=numParams(at)entry=0) at /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/tcop/postgres.c:640
#20138 0x00007fe7fb80cff3 in exec_simple_query (query_string=0x7fe7fdf606b0 "INSERT INTO ts_updates(ts_key, ts_data, ts_frequency) VALUES ('some_id.sector_all.news_all_d',hstore('1900-01-01','-0.395131869823009')||hstore('1900-01-02','-0.395131869823009')||hstore('1"...) at /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/tcop/postgres.c:1001
#20139 PostgresMain (argc=<optimized out>, argv=argv(at)entry=0x7fe7fdd26090, dbname=0x7fe7fdd25f40 "postgres", username=<optimized out>) at /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/tcop/postgres.c:4072
#20140 0x00007fe7fb5fe424 in BackendRun (port=0x7fe7fdd69900) at /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/postmaster/postmaster.c:4177
#20141 BackendStartup (port=0x7fe7fdd69900) at /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/postmaster/postmaster.c:3840
#20142 ServerLoop () at /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/postmaster/postmaster.c:1691
#20143 0x00007fe7fb7c6361 in PostmasterMain (argc=5, argv=<optimized out>) at /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/postmaster/postmaster.c:1315
#20144 0x00007fe7fb5ff0a3 in main (argc=5, argv=0x7fe7fdd25190) at /build/postgresql-9.3-G1RSAD/postgresql-9.3-9.3.11/build/../src/backend/main/main.c:227
Detaching from program: /usr/lib/postgresql/9.3/bin/postgres, process 1521

Is this of any help at all? I really how you can get almost 70 MB done and I can't even get 2-5 MB done. Maybe you can share a brief part of you 70 MB query?

regards, matt bannert

________________________________________
From: Tom Lane [tgl(at)sss(dot)pgh(dot)pa(dot)us]
Sent: Friday, April 08, 2016 9:39 PM
To: Bannert Matthias
Cc: Charles Clavadetscher; pgsql-general(at)postgresql(dot)org
Subject: Re: [GENERAL] max_stack_depth problem though query is substantially smaller

"Bannert Matthias" <bannert(at)kof(dot)ethz(dot)ch> writes:
> Thanks for your reply. I do think it is rather a postgres than an R issue, here's why:
> a) R simply puts an SQL string together. What Charles had posted was an excerpt of that string.
> Basically we have 1.7 MB of that string. Everything else is equal just the hstore contains 40K key value pairs.

Well, as a test I ran a query that included an hstore literal with 4
million key/value pairs (a bit shy of 70MB of query text). I didn't see
any misbehavior on a machine with 2MB max_stack_depth. So there's
something else going on in your situation.

I concur with the suggestion to try to get a stack backtrace from the
point of the error. Setting a breakpoint at errfinish() is usually
an effective strategy when you know that the query will provoke a SQL
error report.

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

regards, tom lane

In response to

Responses

Browse pgsql-general by date

  From Date Subject
Next Message Stephen Frost 2016-04-09 11:42:25 Re: Really unique session ID - PID + connection timestamp?
Previous Message John R Pierce 2016-04-09 10:30:10 Re: Really unique session ID - PID + connection timestamp?